"./sync.test -test.v -test.timeout 1h0m0s -remote TestCryptDrive: -verbose" - Starting (try 1/5) 2025/04/30 16:50:37 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-yovulez1buxa" 2025/04/30 16:50:37 DEBUG : Using config file from "/home/rclone/.rclone.conf" 2025/04/30 16:50:38 DEBUG : Creating backend with remote "TestDrive:crypt/oq8dicu11g0pc2ds2lnqag1s0umk12gt21o3j0hsptghrj7dl370" 2025/04/30 16:50:38 DEBUG : Creating backend with remote "/tmp/rclone771422369" === RUN TestPipe --- PASS: TestPipe (0.00s) === RUN TestPipeConcurrent --- PASS: TestPipeConcurrent (0.04s) === RUN TestPipeOrderBy === RUN TestPipeOrderBy/#00 === RUN TestPipeOrderBy/size === RUN TestPipeOrderBy/name === RUN TestPipeOrderBy/modtime === RUN TestPipeOrderBy/size,ascending === RUN TestPipeOrderBy/name,asc === RUN TestPipeOrderBy/modtime,ascending === RUN TestPipeOrderBy/size,descending === RUN TestPipeOrderBy/name,desc === RUN TestPipeOrderBy/modtime,descending === RUN TestPipeOrderBy/size,mixed,50 === RUN TestPipeOrderBy/size,mixed,51 --- PASS: TestPipeOrderBy (0.00s) --- PASS: TestPipeOrderBy/#00 (0.00s) --- PASS: TestPipeOrderBy/size (0.00s) --- PASS: TestPipeOrderBy/name (0.00s) --- PASS: TestPipeOrderBy/modtime (0.00s) --- PASS: TestPipeOrderBy/size,ascending (0.00s) --- PASS: TestPipeOrderBy/name,asc (0.00s) --- PASS: TestPipeOrderBy/modtime,ascending (0.00s) --- PASS: TestPipeOrderBy/size,descending (0.00s) --- PASS: TestPipeOrderBy/name,desc (0.00s) --- PASS: TestPipeOrderBy/modtime,descending (0.00s) --- PASS: TestPipeOrderBy/size,mixed,50 (0.00s) --- PASS: TestPipeOrderBy/size,mixed,51 (0.00s) === RUN TestNewLess === RUN TestNewLess/blankOK === RUN TestNewLess/tooManyParts === RUN TestNewLess/tooManyParts2 === RUN TestNewLess/badMixed === RUN TestNewLess/unknownComparison === RUN TestNewLess/unknownSortDirection === RUN TestNewLess/size === RUN TestNewLess/name === RUN TestNewLess/modtime === RUN TestNewLess/size,ascending === RUN TestNewLess/name,asc === RUN TestNewLess/modtime,ascending === RUN TestNewLess/size,descending === RUN TestNewLess/name,desc === RUN TestNewLess/modtime,descending === RUN TestNewLess/modtime,mixed === RUN TestNewLess/modtime,mixed,30 --- PASS: TestNewLess (0.00s) --- PASS: TestNewLess/blankOK (0.00s) --- PASS: TestNewLess/tooManyParts (0.00s) --- PASS: TestNewLess/tooManyParts2 (0.00s) --- PASS: TestNewLess/badMixed (0.00s) --- PASS: TestNewLess/unknownComparison (0.00s) --- PASS: TestNewLess/unknownSortDirection (0.00s) --- PASS: TestNewLess/size (0.00s) --- PASS: TestNewLess/name (0.00s) --- PASS: TestNewLess/modtime (0.00s) --- PASS: TestNewLess/size,ascending (0.00s) --- PASS: TestNewLess/name,asc (0.00s) --- PASS: TestNewLess/modtime,ascending (0.00s) --- PASS: TestNewLess/size,descending (0.00s) --- PASS: TestNewLess/name,desc (0.00s) --- PASS: TestNewLess/modtime,descending (0.00s) --- PASS: TestNewLess/modtime,mixed (0.00s) --- PASS: TestNewLess/modtime,mixed,30 (0.00s) === RUN TestRcCopy rc_test.go:16: Skipping test on non local remote --- SKIP: TestRcCopy (0.00s) === RUN TestRcMove rc_test.go:16: Skipping test on non local remote --- SKIP: TestRcMove (0.00s) === RUN TestRcSync rc_test.go:16: Skipping test on non local remote --- SKIP: TestRcSync (0.00s) === RUN TestCopyWithDryRun run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-yovulez1buxa'", Local "Local file system at /tmp/rclone771422369", Modify Window "1ms" 2025/04/30 16:50:40 DEBUG : Added delayed dir = "sub dir", newDst= 2025/04/30 16:50:40 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2025/04/30 16:50:40 NOTICE: sub dir/hello world: Skipped copy as --dry-run is set (size 11) 2025/04/30 16:50:40 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yovulez1buxa': Waiting for checks to finish 2025/04/30 16:50:40 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yovulez1buxa': Waiting for transfers to finish 2025/04/30 16:50:40 NOTICE: sub dir: Skipped set directory modification time as --dry-run is set run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-yovulez1buxa'", Local "Local file system at /tmp/rclone771422369", Modify Window "1ms" --- PASS: TestCopyWithDryRun (2.18s) === RUN TestCopy run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-yovulez1buxa'", Local "Local file system at /tmp/rclone771422369", Modify Window "1ms" 2025/04/30 16:50:41 INFO : sub dir: Set directory modification time (using DirSetModTime) 2025/04/30 16:50:41 DEBUG : Added delayed dir = "sub dir", newDst= 2025/04/30 16:50:41 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2025/04/30 16:50:41 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yovulez1buxa': Waiting for checks to finish 2025/04/30 16:50:41 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yovulez1buxa': Waiting for transfers to finish 2025/04/30 16:50:43 DEBUG : sub dir/hello world: md5 = e02bfef962a4af35e10deeb3563ced8a OK 2025/04/30 16:50:43 INFO : sub dir/hello world: Copied (new) 2025/04/30 16:50:44 INFO : sub dir: Set directory modification time (using DirSetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-yovulez1buxa'", Local "Local file system at /tmp/rclone771422369", Modify Window "1ms" 2025/04/30 16:50:46 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestCopy (6.69s) === RUN TestCopyMetadata run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-yovulez1buxa'", Local "Local file system at /tmp/rclone771422369", Modify Window "1ms" 2025/04/30 16:50:47 DEBUG : metadata sub dir: Making directory with metadata 2025/04/30 16:50:47 INFO : metadata sub dir: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2025/04/30 16:50:47 DEBUG : empty metadata sub dir: Making directory with metadata 2025/04/30 16:50:47 INFO : empty metadata sub dir: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2025/04/30 16:50:47 DEBUG : Local file system at /tmp/rclone771422369: File to upload is small (21 bytes), uploading instead of streaming 2025/04/30 16:50:47 DEBUG : metadata sub dir/hello metadata world: md5 = baa7a013449dbba2b1ed02b5cfb4e1a2 OK 2025/04/30 16:50:47 DEBUG : metadata sub dir/hello metadata world: Size and md5 of src and dst objects identical 2025/04/30 16:50:47 INFO : metadata sub dir: Set directory modification time (using DirSetModTime) 2025/04/30 16:50:48 DEBUG : Google drive root 'crypt/oq8dicu11g0pc2ds2lnqag1s0umk12gt21o3j0hsptghrj7dl370': Skipping btime metadata as can't update it on an existing file: 2025-04-30T16:50:47.902388798Z 2025/04/30 16:50:48 INFO : empty metadata sub dir: Updated directory metadata 2025/04/30 16:50:49 DEBUG : Google drive root 'crypt/oq8dicu11g0pc2ds2lnqag1s0umk12gt21o3j0hsptghrj7dl370': Skipping btime metadata as can't update it on an existing file: 2025-04-30T16:50:47.902388798Z 2025/04/30 16:50:49 INFO : metadata sub dir: Updated directory metadata 2025/04/30 16:50:49 DEBUG : metadata sub dir/hello metadata world: Need to transfer - File not found at Destination 2025/04/30 16:50:49 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yovulez1buxa': Waiting for checks to finish 2025/04/30 16:50:49 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yovulez1buxa': Waiting for transfers to finish 2025/04/30 16:50:51 DEBUG : metadata sub dir/hello metadata world: md5 = 4b2bea5b858d4bd02f3e67fd0b049823 OK 2025/04/30 16:50:51 INFO : metadata sub dir/hello metadata world: Copied (new) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-yovulez1buxa'", Local "Local file system at /tmp/rclone771422369", Modify Window "1ms" 2025/04/30 16:50:54 DEBUG : fg45q1rm3kh00nmmkk4m6ihmrcnel1p7551kqhjr9bk2gtd2gbf0: Rmdir: contains trashed file: "dmuvulfij81f693ur0f1vvbvq9v6iscp56daas3m51n9li5e3470" --- PASS: TestCopyMetadata (8.34s) === RUN TestCopyMetadataNoEmptyDirs run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-yovulez1buxa'", Local "Local file system at /tmp/rclone771422369", Modify Window "1ms" 2025/04/30 16:50:56 DEBUG : metadata sub dir: Making directory with metadata 2025/04/30 16:50:56 INFO : metadata sub dir: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2025/04/30 16:50:56 DEBUG : empty metadata sub dir: Making directory with metadata 2025/04/30 16:50:56 INFO : empty metadata sub dir: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2025/04/30 16:50:56 DEBUG : Local file system at /tmp/rclone771422369: File to upload is small (21 bytes), uploading instead of streaming 2025/04/30 16:50:56 DEBUG : metadata sub dir/hello metadata world: md5 = baa7a013449dbba2b1ed02b5cfb4e1a2 OK 2025/04/30 16:50:56 DEBUG : metadata sub dir/hello metadata world: Size and md5 of src and dst objects identical 2025/04/30 16:50:56 INFO : metadata sub dir: Set directory modification time (using DirSetModTime) 2025/04/30 16:50:56 DEBUG : Added delayed dir = "empty metadata sub dir", newDst= 2025/04/30 16:50:56 DEBUG : Added delayed dir = "metadata sub dir", newDst= 2025/04/30 16:50:56 DEBUG : metadata sub dir/hello metadata world: Need to transfer - File not found at Destination 2025/04/30 16:50:56 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yovulez1buxa': Waiting for checks to finish 2025/04/30 16:50:56 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yovulez1buxa': Waiting for transfers to finish 2025/04/30 16:50:58 DEBUG : metadata sub dir/hello metadata world: md5 = 293bca5eace9b4f04f4d50b91c553a59 OK 2025/04/30 16:50:58 INFO : metadata sub dir/hello metadata world: Copied (new) 2025/04/30 16:50:58 DEBUG : Google drive root 'crypt/oq8dicu11g0pc2ds2lnqag1s0umk12gt21o3j0hsptghrj7dl370': Skipping btime metadata as can't update it on an existing file: 2025-04-30T16:50:56.238400627Z 2025/04/30 16:50:59 INFO : metadata sub dir: Updated directory metadata run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-yovulez1buxa'", Local "Local file system at /tmp/rclone771422369", Modify Window "1ms" 2025/04/30 16:51:02 DEBUG : fg45q1rm3kh00nmmkk4m6ihmrcnel1p7551kqhjr9bk2gtd2gbf0: Rmdir: contains trashed file: "dmuvulfij81f693ur0f1vvbvq9v6iscp56daas3m51n9li5e3470" --- PASS: TestCopyMetadataNoEmptyDirs (7.15s) === RUN TestCopyMissingDirectory run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-yovulez1buxa'", Local "Local file system at /tmp/rclone771422369", Modify Window "1ms" 2025/04/30 16:51:03 DEBUG : Creating backend with remote "/non-existing" 2025/04/30 16:51:03 DEBUG : Config file has changed externally - reloading 2025/04/30 16:51:03 ERROR : Local file system at /non-existing: error reading source root directory: directory not found 2025/04/30 16:51:03 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yovulez1buxa': Waiting for checks to finish 2025/04/30 16:51:03 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yovulez1buxa': Waiting for transfers to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-yovulez1buxa'", Local "Local file system at /tmp/rclone771422369", Modify Window "1ms" --- PASS: TestCopyMissingDirectory (1.07s) === RUN TestCopyNoTraverse run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-yovulez1buxa'", Local "Local file system at /tmp/rclone771422369", Modify Window "1ms" 2025/04/30 16:51:04 DEBUG : Added delayed dir = "sub dir", newDst= 2025/04/30 16:51:04 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2025/04/30 16:51:04 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yovulez1buxa': Waiting for checks to finish 2025/04/30 16:51:04 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yovulez1buxa': Waiting for transfers to finish 2025/04/30 16:51:07 DEBUG : sub dir/hello world: md5 = 0575ebe2982b9752710ff742854ca65e OK 2025/04/30 16:51:07 INFO : sub dir/hello world: Copied (new) 2025/04/30 16:51:07 INFO : sub dir: Set directory modification time (using DirSetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-yovulez1buxa'", Local "Local file system at /tmp/rclone771422369", Modify Window "1ms" 2025/04/30 16:51:09 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestCopyNoTraverse (6.23s) === RUN TestCopyCheckFirst run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-yovulez1buxa'", Local "Local file system at /tmp/rclone771422369", Modify Window "1ms" 2025/04/30 16:51:10 INFO : Encrypted drive 'TestCryptDrive:rclone-test-yovulez1buxa': Running all checks before starting transfers 2025/04/30 16:51:10 DEBUG : Added delayed dir = "sub dir", newDst= 2025/04/30 16:51:10 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2025/04/30 16:51:10 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yovulez1buxa': Waiting for checks to finish 2025/04/30 16:51:10 INFO : Encrypted drive 'TestCryptDrive:rclone-test-yovulez1buxa': Checks finished, now starting transfers 2025/04/30 16:51:10 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yovulez1buxa': Waiting for transfers to finish 2025/04/30 16:51:13 DEBUG : sub dir/hello world: md5 = 0a1ddc48909f33ca5667f9faef09ea33 OK 2025/04/30 16:51:13 INFO : sub dir/hello world: Copied (new) 2025/04/30 16:51:13 INFO : sub dir: Set directory modification time (using DirSetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-yovulez1buxa'", Local "Local file system at /tmp/rclone771422369", Modify Window "1ms" 2025/04/30 16:51:15 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestCopyCheckFirst (5.90s) === RUN TestSyncNoTraverse run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-yovulez1buxa'", Local "Local file system at /tmp/rclone771422369", Modify Window "1ms" 2025/04/30 16:51:16 ERROR : Ignoring --no-traverse with sync 2025/04/30 16:51:16 DEBUG : Added delayed dir = "sub dir", newDst= 2025/04/30 16:51:16 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2025/04/30 16:51:16 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yovulez1buxa': Waiting for checks to finish 2025/04/30 16:51:16 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yovulez1buxa': Waiting for transfers to finish 2025/04/30 16:51:19 DEBUG : sub dir/hello world: md5 = 66356f51cfa292e7b820a4da47bee5fa OK 2025/04/30 16:51:19 INFO : sub dir/hello world: Copied (new) 2025/04/30 16:51:19 DEBUG : Waiting for deletions to finish 2025/04/30 16:51:19 INFO : sub dir: Set directory modification time (using DirSetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-yovulez1buxa'", Local "Local file system at /tmp/rclone771422369", Modify Window "1ms" 2025/04/30 16:51:21 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestSyncNoTraverse (6.06s) === RUN TestCopyWithDepth run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-yovulez1buxa'", Local "Local file system at /tmp/rclone771422369", Modify Window "1ms" 2025/04/30 16:51:22 DEBUG : hello world2: Need to transfer - File not found at Destination 2025/04/30 16:51:22 DEBUG : Added delayed dir = "sub dir", newDst= 2025/04/30 16:51:22 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yovulez1buxa': Waiting for checks to finish 2025/04/30 16:51:22 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yovulez1buxa': Waiting for transfers to finish 2025/04/30 16:51:24 DEBUG : hello world2: md5 = 5a506f558a99aaccd2a0355444036c64 OK 2025/04/30 16:51:24 INFO : hello world2: Copied (new) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-yovulez1buxa'", Local "Local file system at /tmp/rclone771422369", Modify Window "1ms" --- PASS: TestCopyWithDepth (3.48s) === RUN TestCopyWithFilesFrom run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-yovulez1buxa'", Local "Local file system at /tmp/rclone771422369", Modify Window "1ms" 2025/04/30 16:51:26 DEBUG : potato2: Need to transfer - File not found at Destination 2025/04/30 16:51:26 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yovulez1buxa': Waiting for checks to finish 2025/04/30 16:51:26 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yovulez1buxa': Waiting for transfers to finish 2025/04/30 16:51:27 DEBUG : potato2: md5 = b715e87fc90d72c8a890dbc73a4edb7d OK 2025/04/30 16:51:27 INFO : potato2: Copied (new) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-yovulez1buxa'", Local "Local file system at /tmp/rclone771422369", Modify Window "1ms" --- PASS: TestCopyWithFilesFrom (3.45s) === RUN TestCopyWithFilesFromAndNoTraverse run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-yovulez1buxa'", Local "Local file system at /tmp/rclone771422369", Modify Window "1ms" 2025/04/30 16:51:29 DEBUG : potato2: Need to transfer - File not found at Destination 2025/04/30 16:51:29 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yovulez1buxa': Waiting for checks to finish 2025/04/30 16:51:29 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yovulez1buxa': Waiting for transfers to finish 2025/04/30 16:51:31 DEBUG : potato2: md5 = aa5f288cb8f7d1ab9b2820163ed3996f OK 2025/04/30 16:51:31 INFO : potato2: Copied (new) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-yovulez1buxa'", Local "Local file system at /tmp/rclone771422369", Modify Window "1ms" --- PASS: TestCopyWithFilesFromAndNoTraverse (3.40s) === RUN TestCopyEmptyDirectories run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-yovulez1buxa'", Local "Local file system at /tmp/rclone771422369", Modify Window "1ms" 2025/04/30 16:51:32 DEBUG : sub dir2/sub sub dir2: Making directory with metadata 2025/04/30 16:51:32 INFO : sub dir2/sub sub dir2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2025/04/30 16:51:32 INFO : sub dir2: Set directory modification time (using DirSetModTime) 2025/04/30 16:51:32 INFO : sub dir: Set directory modification time (using DirSetModTime) 2025/04/30 16:51:33 DEBUG : sub dir: Making directory with metadata 2025/04/30 16:51:33 INFO : sub dir: Made directory with metadata (mtime=2001-02-03T04:05:06.499999999Z) 2025/04/30 16:51:33 DEBUG : sub dir2: Making directory with metadata 2025/04/30 16:51:34 INFO : sub dir2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2025/04/30 16:51:34 DEBUG : sub dir2/sub sub dir2: Making directory with metadata 2025/04/30 16:51:34 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2025/04/30 16:51:35 INFO : sub dir2/sub sub dir2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2025/04/30 16:51:35 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yovulez1buxa': Waiting for checks to finish 2025/04/30 16:51:35 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yovulez1buxa': Waiting for transfers to finish 2025/04/30 16:51:36 DEBUG : sub dir/hello world: md5 = 5a259a3a1e53823445365138eb13e067 OK 2025/04/30 16:51:36 INFO : sub dir/hello world: Copied (new) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-yovulez1buxa'", Local "Local file system at /tmp/rclone771422369", Modify Window "1ms" 2025/04/30 16:51:40 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc: Rmdir: contains trashed file: "cv6a9uf28ngrajena8kt5ijjn0" 2025/04/30 16:51:40 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestCopyEmptyDirectories (8.94s) === RUN TestCopyNoEmptyDirectories run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-yovulez1buxa'", Local "Local file system at /tmp/rclone771422369", Modify Window "1ms" 2025/04/30 16:51:41 INFO : sub dir2: Making directory 2025/04/30 16:51:41 DEBUG : sub dir2/sub sub dir2: Making directory with metadata 2025/04/30 16:51:41 INFO : sub dir2/sub sub dir2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2025/04/30 16:51:42 DEBUG : Added delayed dir = "sub dir", newDst= 2025/04/30 16:51:42 DEBUG : Added delayed dir = "sub dir2", newDst= 2025/04/30 16:51:42 DEBUG : Added delayed dir = "sub dir2/sub sub dir2", newDst= 2025/04/30 16:51:42 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2025/04/30 16:51:42 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yovulez1buxa': Waiting for checks to finish 2025/04/30 16:51:42 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yovulez1buxa': Waiting for transfers to finish 2025/04/30 16:51:44 DEBUG : sub dir/hello world: md5 = f490bcef11ac36772352f2db885c6f7c OK 2025/04/30 16:51:44 INFO : sub dir/hello world: Copied (new) 2025/04/30 16:51:44 INFO : sub dir: Set directory modification time (using DirSetModTime) 2025/04/30 16:51:46 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestCopyNoEmptyDirectories (5.72s) === RUN TestMoveEmptyDirectories run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-yovulez1buxa'", Local "Local file system at /tmp/rclone771422369", Modify Window "1ms" 2025/04/30 16:51:47 DEBUG : sub dir2: Making directory with metadata 2025/04/30 16:51:47 INFO : sub dir2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2025/04/30 16:51:47 DEBUG : sub dir: Making directory with metadata 2025/04/30 16:51:48 INFO : sub dir: Made directory with metadata (mtime=2025-04-30T16:51:47.658473751Z) 2025/04/30 16:51:48 DEBUG : sub dir2: Making directory with metadata 2025/04/30 16:51:49 INFO : sub dir2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2025/04/30 16:51:49 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2025/04/30 16:51:49 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yovulez1buxa': Waiting for checks to finish 2025/04/30 16:51:49 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yovulez1buxa': Waiting for transfers to finish 2025/04/30 16:51:50 DEBUG : sub dir/hello world: md5 = 2307a1c5afd856b7864fc316703e10e1 OK 2025/04/30 16:51:50 INFO : sub dir/hello world: Copied (new) 2025/04/30 16:51:50 INFO : sub dir/hello world: Deleted run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-yovulez1buxa'", Local "Local file system at /tmp/rclone771422369", Modify Window "1ms" 2025/04/30 16:51:53 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestMoveEmptyDirectories (7.46s) === RUN TestSyncNoUpdateDirModtime run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-yovulez1buxa'", Local "Local file system at /tmp/rclone771422369", Modify Window "1ms" 2025/04/30 16:51:55 DEBUG : sub dir no update dir modtime: Making directory with metadata 2025/04/30 16:51:55 INFO : sub dir no update dir modtime: Made directory with metadata (mtime=2001-02-03T04:05:06.499999999Z) 2025/04/30 16:51:56 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yovulez1buxa': Waiting for checks to finish 2025/04/30 16:51:56 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yovulez1buxa': Waiting for transfers to finish 2025/04/30 16:51:56 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-yovulez1buxa'", Local "Local file system at /tmp/rclone771422369", Modify Window "1ms" --- PASS: TestSyncNoUpdateDirModtime (4.56s) === RUN TestMoveNoEmptyDirectories run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-yovulez1buxa'", Local "Local file system at /tmp/rclone771422369", Modify Window "1ms" 2025/04/30 16:51:59 INFO : sub dir2: Making directory 2025/04/30 16:51:59 DEBUG : Added delayed dir = "sub dir", newDst= 2025/04/30 16:51:59 DEBUG : Added delayed dir = "sub dir2", newDst= 2025/04/30 16:51:59 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2025/04/30 16:51:59 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yovulez1buxa': Waiting for checks to finish 2025/04/30 16:51:59 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yovulez1buxa': Waiting for transfers to finish 2025/04/30 16:52:02 DEBUG : sub dir/hello world: md5 = c85c430b8c68d7bb00d337c2482088e2 OK 2025/04/30 16:52:02 INFO : sub dir/hello world: Copied (new) 2025/04/30 16:52:02 INFO : sub dir/hello world: Deleted 2025/04/30 16:52:02 INFO : sub dir: Set directory modification time (using DirSetModTime) 2025/04/30 16:52:04 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestMoveNoEmptyDirectories (5.40s) === RUN TestSyncEmptyDirectories run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-yovulez1buxa'", Local "Local file system at /tmp/rclone771422369", Modify Window "1ms" 2025/04/30 16:52:05 DEBUG : sub dir2: Making directory with metadata 2025/04/30 16:52:05 INFO : sub dir2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2025/04/30 16:52:05 INFO : sub dir: Set directory modification time (using DirSetModTime) 2025/04/30 16:52:05 DEBUG : sub dir: Making directory with metadata 2025/04/30 16:52:06 INFO : sub dir: Made directory with metadata (mtime=2001-02-03T04:05:06.499999999Z) 2025/04/30 16:52:06 DEBUG : sub dir2: Making directory with metadata 2025/04/30 16:52:06 INFO : sub dir2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2025/04/30 16:52:06 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2025/04/30 16:52:06 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yovulez1buxa': Waiting for checks to finish 2025/04/30 16:52:06 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yovulez1buxa': Waiting for transfers to finish 2025/04/30 16:52:08 DEBUG : sub dir/hello world: md5 = 0cf70d640eaf35fff5a01f3e79597016 OK 2025/04/30 16:52:08 INFO : sub dir/hello world: Copied (new) 2025/04/30 16:52:08 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-yovulez1buxa'", Local "Local file system at /tmp/rclone771422369", Modify Window "1ms" 2025/04/30 16:52:11 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestSyncEmptyDirectories (7.52s) === RUN TestSyncSetDelayedModTimes run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-yovulez1buxa'", Local "Local file system at /tmp/rclone771422369", 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-yovulez1buxa'", Local "Local file system at /tmp/rclone771422369", Modify Window "1ms" 2025/04/30 16:52:13 INFO : sub dir2: Making directory 2025/04/30 16:52:13 DEBUG : Added delayed dir = "sub dir", newDst= 2025/04/30 16:52:13 DEBUG : Added delayed dir = "sub dir2", newDst= 2025/04/30 16:52:13 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2025/04/30 16:52:13 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yovulez1buxa': Waiting for checks to finish 2025/04/30 16:52:13 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yovulez1buxa': Waiting for transfers to finish 2025/04/30 16:52:15 DEBUG : sub dir/hello world: md5 = a08dee2d08ddfae52c64ec444a76896b OK 2025/04/30 16:52:15 INFO : sub dir/hello world: Copied (new) 2025/04/30 16:52:15 DEBUG : Waiting for deletions to finish 2025/04/30 16:52:16 INFO : sub dir: Set directory modification time (using DirSetModTime) 2025/04/30 16:52:17 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestSyncNoEmptyDirectories (5.59s) === RUN TestServerSideCopy run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-yovulez1buxa'", Local "Local file system at /tmp/rclone771422369", Modify Window "1ms" 2025/04/30 16:52:21 DEBUG : sub dir/hello world: md5 = 6655d5db0c7623fe3c9cdc97ec019d2d OK 2025/04/30 16:52:21 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-vuwemik7ruqa" 2025/04/30 16:52:21 DEBUG : Creating backend with remote "TestDrive:crypt/0negl0itemmh4lofgbi11gm76t4ge6ppr9l7j3otu13f27kh517g" sync_test.go:590: Server side copy (if possible) Encrypted drive 'TestCryptDrive:rclone-test-yovulez1buxa' -> Encrypted drive 'TestCryptDrive:rclone-test-vuwemik7ruqa' 2025/04/30 16:52:22 DEBUG : Added delayed dir = "sub dir", newDst= 2025/04/30 16:52:23 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2025/04/30 16:52:23 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vuwemik7ruqa': Waiting for checks to finish 2025/04/30 16:52:23 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vuwemik7ruqa': Waiting for transfers to finish 2025/04/30 16:52:25 INFO : sub dir/hello world: Copied (server-side copy) 2025/04/30 16:52:26 INFO : sub dir: Set directory modification time (using DirSetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-yovulez1buxa'", Local "Local file system at /tmp/rclone771422369", Modify Window "1ms" 2025/04/30 16:52:26 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vuwemik7ruqa': Purge remote 2025/04/30 16:52:28 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestServerSideCopy (11.06s) === RUN TestCopyOverSelf run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-yovulez1buxa'", Local "Local file system at /tmp/rclone771422369", Modify Window "1ms" 2025/04/30 16:52:31 DEBUG : sub dir/hello world: md5 = 5fa9a90cd2605edb40aa1c05b82d8dd7 OK 2025/04/30 16:52:33 INFO : sub dir: Set directory modification time (using SetModTime) 2025/04/30 16:52:33 DEBUG : Added delayed dir = "sub dir", newDst=sub dir 2025/04/30 16:52:33 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yovulez1buxa': Waiting for checks to finish 2025/04/30 16:52:33 DEBUG : sub dir/hello world: Sizes differ (src 17 vs dst 11) 2025/04/30 16:52:33 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yovulez1buxa': Waiting for transfers to finish 2025/04/30 16:52:34 DEBUG : sub dir/hello world: md5 = 4a61e02ba436eb05b1e160c144975e49 OK 2025/04/30 16:52:34 INFO : sub dir/hello world: Copied (replaced existing) 2025/04/30 16:52:35 INFO : sub dir: Set directory modification time (using SetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-yovulez1buxa'", Local "Local file system at /tmp/rclone771422369", Modify Window "1ms" 2025/04/30 16:52:36 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestCopyOverSelf (8.19s) === RUN TestServerSideCopyOverSelf run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-yovulez1buxa'", Local "Local file system at /tmp/rclone771422369", Modify Window "1ms" 2025/04/30 16:52:40 DEBUG : sub dir/hello world: md5 = 804fe3073ad97624ffbcc1b7c5b9683f OK 2025/04/30 16:52:40 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-tenaceg2yegu" 2025/04/30 16:52:40 DEBUG : Creating backend with remote "TestDrive:crypt/6ck2phbibj5vfr0rac3nk3qmhooenjpq36dn66mjec3qo2tsa350" sync_test.go:626: Server side copy (if possible) Encrypted drive 'TestCryptDrive:rclone-test-yovulez1buxa' -> Encrypted drive 'TestCryptDrive:rclone-test-tenaceg2yegu' 2025/04/30 16:52:42 DEBUG : Added delayed dir = "sub dir", newDst= 2025/04/30 16:52:42 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2025/04/30 16:52:42 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tenaceg2yegu': Waiting for checks to finish 2025/04/30 16:52:42 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tenaceg2yegu': Waiting for transfers to finish 2025/04/30 16:52:45 INFO : sub dir/hello world: Copied (server-side copy) 2025/04/30 16:52:45 INFO : sub dir: Set directory modification time (using DirSetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-yovulez1buxa'", Local "Local file system at /tmp/rclone771422369", Modify Window "1ms" 2025/04/30 16:52:47 DEBUG : sub dir/hello world: md5 = 2ea3485546e38bc5875a32e431124737 OK 2025/04/30 16:52:48 DEBUG : sub dir: Directory modification time the same (differ by 0s, within tolerance 1ms) 2025/04/30 16:52:48 DEBUG : Added delayed dir = "sub dir", newDst=sub dir 2025/04/30 16:52:48 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tenaceg2yegu': Waiting for checks to finish 2025/04/30 16:52:48 DEBUG : sub dir/hello world: Sizes differ (src 17 vs dst 11) 2025/04/30 16:52:48 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tenaceg2yegu': Waiting for transfers to finish 2025/04/30 16:52:50 INFO : sub dir/hello world: Copied (server-side copy) 2025/04/30 16:52:50 INFO : sub dir: Set directory modification time (using SetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-yovulez1buxa'", Local "Local file system at /tmp/rclone771422369", Modify Window "1ms" 2025/04/30 16:52:51 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tenaceg2yegu': Purge remote 2025/04/30 16:52:53 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestServerSideCopyOverSelf (16.79s) === RUN TestMoveOverSelf run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-yovulez1buxa'", Local "Local file system at /tmp/rclone771422369", Modify Window "1ms" 2025/04/30 16:52:56 DEBUG : sub dir/hello world: md5 = 2b96759f5ebf894f38601c6510db0306 OK 2025/04/30 16:52:58 INFO : sub dir: Set directory modification time (using SetModTime) 2025/04/30 16:52:58 DEBUG : Added delayed dir = "sub dir", newDst=sub dir 2025/04/30 16:52:58 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yovulez1buxa': Waiting for checks to finish 2025/04/30 16:52:58 DEBUG : sub dir/hello world: Sizes differ (src 17 vs dst 11) 2025/04/30 16:52:58 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yovulez1buxa': Waiting for transfers to finish 2025/04/30 16:52:59 DEBUG : sub dir/hello world: md5 = 2305f2c86ca00df1205bf8a8cc7112d3 OK 2025/04/30 16:52:59 INFO : sub dir/hello world: Copied (replaced existing) 2025/04/30 16:52:59 INFO : sub dir/hello world: Deleted 2025/04/30 16:53:00 INFO : sub dir: Set directory modification time (using SetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-yovulez1buxa'", Local "Local file system at /tmp/rclone771422369", Modify Window "1ms" 2025/04/30 16:53:01 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestMoveOverSelf (8.55s) === RUN TestServerSideMoveOverSelf run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-yovulez1buxa'", Local "Local file system at /tmp/rclone771422369", Modify Window "1ms" 2025/04/30 16:53:05 DEBUG : sub dir/hello world: md5 = 18525b27f6066727a873343da502b39f OK 2025/04/30 16:53:06 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-teciyot2bicu" 2025/04/30 16:53:06 DEBUG : Creating backend with remote "TestDrive:crypt/rr2jeu13olqiphp43cb57v1eq77o0ij4ouactr0morul5iub516g" sync_test.go:671: Server side copy (if possible) Encrypted drive 'TestCryptDrive:rclone-test-yovulez1buxa' -> Encrypted drive 'TestCryptDrive:rclone-test-teciyot2bicu' 2025/04/30 16:53:07 DEBUG : Added delayed dir = "sub dir", newDst= 2025/04/30 16:53:07 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2025/04/30 16:53:07 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-teciyot2bicu': Waiting for checks to finish 2025/04/30 16:53:07 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-teciyot2bicu': Waiting for transfers to finish 2025/04/30 16:53:10 INFO : sub dir/hello world: Copied (server-side copy) 2025/04/30 16:53:10 INFO : sub dir: Set directory modification time (using DirSetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-yovulez1buxa'", Local "Local file system at /tmp/rclone771422369", Modify Window "1ms" 2025/04/30 16:53:12 DEBUG : sub dir/hello world: md5 = 3f4aa3ff4a6f7374e54eac2b38539cc3 OK 2025/04/30 16:53:13 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-teciyot2bicu': Using server-side directory move 2025/04/30 16:53:13 INFO : Encrypted drive 'TestCryptDrive:rclone-test-teciyot2bicu': Server side directory move failed - fallback to file moves: can't copy directory - destination already exists 2025/04/30 16:53:13 DEBUG : sub dir: Directory modification time the same (differ by 0s, within tolerance 1ms) 2025/04/30 16:53:13 DEBUG : Added delayed dir = "sub dir", newDst=sub dir 2025/04/30 16:53:13 DEBUG : sub dir/hello world: Sizes differ (src 17 vs dst 11) 2025/04/30 16:53:13 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-teciyot2bicu': Waiting for checks to finish 2025/04/30 16:53:13 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-teciyot2bicu': Waiting for transfers to finish 2025/04/30 16:53:14 INFO : sub dir/hello world: Deleted 2025/04/30 16:53:15 INFO : sub dir/hello world: Moved (server-side) 2025/04/30 16:53:15 INFO : sub dir: Set directory modification time (using SetModTime) 2025/04/30 16:53:18 DEBUG : sub dir/hello world: md5 = 66a567e18bc491bc2ed7a76c8be5d93f OK 2025/04/30 16:53:18 DEBUG : testing file moves 2025/04/30 16:53:18 DEBUG : sub dir: Directory modification time the same (differ by 0s, within tolerance 1ms) 2025/04/30 16:53:18 DEBUG : Added delayed dir = "sub dir", newDst=sub dir 2025/04/30 16:53:19 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-teciyot2bicu': Waiting for checks to finish 2025/04/30 16:53:19 DEBUG : sub dir/hello world: Sizes differ (src 24 vs dst 17) 2025/04/30 16:53:19 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-teciyot2bicu': Waiting for transfers to finish 2025/04/30 16:53:19 INFO : sub dir/hello world: Deleted 2025/04/30 16:53:20 INFO : sub dir/hello world: Moved (server-side) 2025/04/30 16:53:20 INFO : sub dir: Set directory modification time (using SetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-yovulez1buxa'", Local "Local file system at /tmp/rclone771422369", Modify Window "1ms" 2025/04/30 16:53:21 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-teciyot2bicu': Purge remote --- PASS: TestServerSideMoveOverSelf (21.37s) === RUN TestCopyAfterDelete run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-yovulez1buxa'", Local "Local file system at /tmp/rclone771422369", Modify Window "1ms" 2025/04/30 16:53:26 DEBUG : sub dir/hello world: md5 = 81ef60c6edbad1d6810831e3cfb00cc5 OK 2025/04/30 16:53:26 ERROR : : error listing: directory not found 2025/04/30 16:53:27 INFO : Local file system at /tmp/rclone771422369: Making directory 2025/04/30 16:53:27 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yovulez1buxa': Waiting for checks to finish 2025/04/30 16:53:27 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yovulez1buxa': Waiting for transfers to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-yovulez1buxa'", Local "Local file system at /tmp/rclone771422369", Modify Window "1ms" 2025/04/30 16:53:29 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestCopyAfterDelete (5.96s) === RUN TestCopyRedownload run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-yovulez1buxa'", Local "Local file system at /tmp/rclone771422369", Modify Window "1ms" 2025/04/30 16:53:32 DEBUG : sub dir/hello world: md5 = 63c7e54d91195e95cf023620537f851d OK 2025/04/30 16:53:33 DEBUG : Added delayed dir = "sub dir", newDst= 2025/04/30 16:53:33 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2025/04/30 16:53:33 DEBUG : Local file system at /tmp/rclone771422369: Waiting for checks to finish 2025/04/30 16:53:33 DEBUG : Local file system at /tmp/rclone771422369: Waiting for transfers to finish 2025/04/30 16:53:35 DEBUG : sub dir/hello world.285f0a30.partial: renamed to: sub dir/hello world 2025/04/30 16:53:35 INFO : sub dir/hello world: Copied (new) 2025/04/30 16:53:35 INFO : sub dir: Set directory modification time (using DirSetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-yovulez1buxa'", Local "Local file system at /tmp/rclone771422369", Modify Window "1ms" 2025/04/30 16:53:36 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestCopyRedownload (7.51s) === RUN TestSyncBasedOnCheckSum run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-yovulez1buxa'", Local "Local file system at /tmp/rclone771422369", Modify Window "1ms" 2025/04/30 16:53:38 DEBUG : check sum: Need to transfer - File not found at Destination 2025/04/30 16:53:38 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yovulez1buxa': Waiting for checks to finish 2025/04/30 16:53:38 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yovulez1buxa': Waiting for transfers to finish 2025/04/30 16:53:39 DEBUG : check sum: md5 = 240ce1c0c5e85f81c145d2d6a29ec132 OK 2025/04/30 16:53:39 INFO : check sum: Copied (new) 2025/04/30 16:53:39 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-yovulez1buxa'", Local "Local file system at /tmp/rclone771422369", Modify Window "1ms" 2025/04/30 16:53:40 NOTICE: Encrypted drive 'TestCryptDrive:rclone-test-yovulez1buxa': --checksum is in use but the source and destination have no hashes in common; falling back to --size-only 2025/04/30 16:53:40 DEBUG : check sum: Size of src and dst objects identical 2025/04/30 16:53:40 DEBUG : check sum: Unchanged skipping 2025/04/30 16:53:40 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yovulez1buxa': Waiting for checks to finish 2025/04/30 16:53:40 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yovulez1buxa': Waiting for transfers to finish 2025/04/30 16:53:40 DEBUG : Waiting for deletions to finish 2025/04/30 16:53:40 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-yovulez1buxa'", Local "Local file system at /tmp/rclone771422369", Modify Window "1ms" --- PASS: TestSyncBasedOnCheckSum (4.52s) === RUN TestSyncSizeOnly run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-yovulez1buxa'", Local "Local file system at /tmp/rclone771422369", Modify Window "1ms" 2025/04/30 16:53:42 DEBUG : sizeonly: Need to transfer - File not found at Destination 2025/04/30 16:53:42 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yovulez1buxa': Waiting for checks to finish 2025/04/30 16:53:42 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yovulez1buxa': Waiting for transfers to finish 2025/04/30 16:53:44 DEBUG : sizeonly: md5 = a065c25f8857bb9d9a0e006d64e3409d OK 2025/04/30 16:53:44 INFO : sizeonly: Copied (new) 2025/04/30 16:53:44 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-yovulez1buxa'", Local "Local file system at /tmp/rclone771422369", Modify Window "1ms" 2025/04/30 16:53:44 DEBUG : sizeonly: Sizes identical 2025/04/30 16:53:44 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yovulez1buxa': Waiting for checks to finish 2025/04/30 16:53:44 DEBUG : sizeonly: Unchanged skipping 2025/04/30 16:53:44 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yovulez1buxa': Waiting for transfers to finish 2025/04/30 16:53:44 DEBUG : Waiting for deletions to finish 2025/04/30 16:53:44 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-yovulez1buxa'", Local "Local file system at /tmp/rclone771422369", Modify Window "1ms" --- PASS: TestSyncSizeOnly (3.95s) === RUN TestSyncIgnoreSize run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-yovulez1buxa'", Local "Local file system at /tmp/rclone771422369", Modify Window "1ms" 2025/04/30 16:53:46 DEBUG : ignore-size: Need to transfer - File not found at Destination 2025/04/30 16:53:46 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yovulez1buxa': Waiting for checks to finish 2025/04/30 16:53:46 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yovulez1buxa': Waiting for transfers to finish 2025/04/30 16:53:48 DEBUG : ignore-size: md5 = f0777117789082ef83c6afd5d26f1a83 OK 2025/04/30 16:53:48 INFO : ignore-size: Copied (new) 2025/04/30 16:53:48 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-yovulez1buxa'", Local "Local file system at /tmp/rclone771422369", Modify Window "1ms" 2025/04/30 16:53:48 DEBUG : ignore-size: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/30 16:53:48 DEBUG : ignore-size: Unchanged skipping 2025/04/30 16:53:48 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yovulez1buxa': Waiting for checks to finish 2025/04/30 16:53:48 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yovulez1buxa': Waiting for transfers to finish 2025/04/30 16:53:48 DEBUG : Waiting for deletions to finish 2025/04/30 16:53:48 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-yovulez1buxa'", Local "Local file system at /tmp/rclone771422369", Modify Window "1ms" --- PASS: TestSyncIgnoreSize (4.38s) === RUN TestSyncIgnoreTimes run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-yovulez1buxa'", Local "Local file system at /tmp/rclone771422369", Modify Window "1ms" 2025/04/30 16:53:52 DEBUG : existing: md5 = 534a72ea964e9b46cf1aef717d3e9457 OK 2025/04/30 16:53:52 DEBUG : existing: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/30 16:53:52 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yovulez1buxa': Waiting for checks to finish 2025/04/30 16:53:52 DEBUG : existing: Unchanged skipping 2025/04/30 16:53:52 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yovulez1buxa': Waiting for transfers to finish 2025/04/30 16:53:52 DEBUG : Waiting for deletions to finish 2025/04/30 16:53:52 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-yovulez1buxa'", Local "Local file system at /tmp/rclone771422369", Modify Window "1ms" 2025/04/30 16:53:53 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yovulez1buxa': Waiting for checks to finish 2025/04/30 16:53:53 DEBUG : existing: Transferring unconditionally as --ignore-times is in use 2025/04/30 16:53:53 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yovulez1buxa': Waiting for transfers to finish 2025/04/30 16:53:54 DEBUG : existing: md5 = 4f5111bb9d71cc3c1fb1c2018270d67a OK 2025/04/30 16:53:54 INFO : existing: Copied (replaced existing) 2025/04/30 16:53:54 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-yovulez1buxa'", Local "Local file system at /tmp/rclone771422369", Modify Window "1ms" --- PASS: TestSyncIgnoreTimes (5.85s) === RUN TestSyncIgnoreExisting run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-yovulez1buxa'", Local "Local file system at /tmp/rclone771422369", Modify Window "1ms" 2025/04/30 16:53:56 DEBUG : existing: Need to transfer - File not found at Destination 2025/04/30 16:53:56 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yovulez1buxa': Waiting for checks to finish 2025/04/30 16:53:56 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yovulez1buxa': Waiting for transfers to finish 2025/04/30 16:53:58 DEBUG : existing: md5 = d0942cf356353294ffb070b0f319061c OK 2025/04/30 16:53:58 INFO : existing: Copied (new) 2025/04/30 16:53:58 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-yovulez1buxa'", Local "Local file system at /tmp/rclone771422369", Modify Window "1ms" 2025/04/30 16:53:58 DEBUG : existing: Destination exists, skipping 2025/04/30 16:53:58 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yovulez1buxa': Waiting for checks to finish 2025/04/30 16:53:58 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yovulez1buxa': Waiting for transfers to finish 2025/04/30 16:53:58 DEBUG : Waiting for deletions to finish 2025/04/30 16:53:58 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-yovulez1buxa'", Local "Local file system at /tmp/rclone771422369", Modify Window "1ms" --- PASS: TestSyncIgnoreExisting (4.06s) === RUN TestSyncIgnoreErrors run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-yovulez1buxa'", Local "Local file system at /tmp/rclone771422369", Modify Window "1ms" 2025/04/30 16:54:02 DEBUG : b/potato: md5 = f8a14b91738d80f421fadcfaf98fcf74 OK 2025/04/30 16:54:05 DEBUG : c/non empty space: md5 = 86ef2223970257833e17164586cc50af OK 2025/04/30 16:54:05 INFO : d: Making directory 2025/04/30 16:54:07 DEBUG : Added delayed dir = "a", newDst= 2025/04/30 16:54:07 INFO : c: Set directory modification time (using SetModTime) 2025/04/30 16:54:07 DEBUG : Added delayed dir = "c", newDst=c 2025/04/30 16:54:07 DEBUG : a/potato2: Need to transfer - File not found at Destination 2025/04/30 16:54:07 DEBUG : c/non empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/04/30 16:54:07 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yovulez1buxa': Waiting for checks to finish 2025/04/30 16:54:07 DEBUG : c/non empty space: Unchanged skipping 2025/04/30 16:54:07 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yovulez1buxa': Waiting for transfers to finish 2025/04/30 16:54:09 DEBUG : a/potato2: md5 = bf7dad619b83b95d4471a2593ef1b684 OK 2025/04/30 16:54:09 INFO : a/potato2: Copied (new) 2025/04/30 16:54:09 DEBUG : Waiting for deletions to finish 2025/04/30 16:54:10 INFO : b/potato: Deleted 2025/04/30 16:54:10 INFO : a: Set directory modification time (using DirSetModTime) 2025/04/30 16:54:10 INFO : d: Removing directory 2025/04/30 16:54:11 INFO : b: Removing directory 2025/04/30 16:54:11 DEBUG : 32d8ua6196mc1r7qkfog53rkg0: Rmdir: contains trashed file: "2m507n64kafsi59v9q71r281a4" 2025/04/30 16:54:12 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yovulez1buxa': deleted 2 directories run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-yovulez1buxa'", Local "Local file system at /tmp/rclone771422369", Modify Window "1ms" 2025/04/30 16:54:14 DEBUG : 3i9du405pfogq3ncai6pg7ouio: Rmdir: contains trashed file: "982d3pss7t5pn0il16r2foj31s" 2025/04/30 16:54:15 DEBUG : 2bsvlrk2ne1lfitm6tttcu0qt8: Rmdir: contains trashed file: "89l8renevh3mji1c8r1p7qn6tg" --- PASS: TestSyncIgnoreErrors (15.87s) === RUN TestSyncAfterChangingModtimeOnly run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-yovulez1buxa'", Local "Local file system at /tmp/rclone771422369", Modify Window "1ms" 2025/04/30 16:54:18 DEBUG : empty space: md5 = 325ed7db89959e88aebda2b93ae0487d OK 2025/04/30 16:54:18 DEBUG : empty space: Modification times differ by -95456h54m52.624456789s: 2011-12-25 12:59:59.123456789 +0000 UTC, 2001-02-03 04:05:06.499 +0000 UTC 2025/04/30 16:54:18 NOTICE: empty space: Skipped copy as --dry-run is set (size 1) 2025/04/30 16:54:18 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yovulez1buxa': Waiting for checks to finish 2025/04/30 16:54:18 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yovulez1buxa': Waiting for transfers to finish 2025/04/30 16:54:18 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-yovulez1buxa'", Local "Local file system at /tmp/rclone771422369", Modify Window "1ms" 2025/04/30 16:54:19 DEBUG : empty space: Modification times differ by -95456h54m52.624456789s: 2011-12-25 12:59:59.123456789 +0000 UTC, 2001-02-03 04:05:06.499 +0000 UTC 2025/04/30 16:54:19 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yovulez1buxa': Waiting for checks to finish 2025/04/30 16:54:19 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yovulez1buxa': Waiting for transfers to finish 2025/04/30 16:54:20 DEBUG : empty space: md5 = 8fb2c18d114b70daacf6a2f306bc6c5b OK 2025/04/30 16:54:20 INFO : empty space: Copied (replaced existing) 2025/04/30 16:54:20 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-yovulez1buxa'", Local "Local file system at /tmp/rclone771422369", Modify Window "1ms" --- PASS: TestSyncAfterChangingModtimeOnly (6.09s) === RUN TestSyncAfterChangingModtimeOnlyWithNoUpdateModTime run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-yovulez1buxa'", Local "Local file system at /tmp/rclone771422369", Modify Window "1ms" sync_test.go:1016: Can't check this if no hashes supported --- PASS: TestSyncAfterChangingModtimeOnlyWithNoUpdateModTime (0.46s) === RUN TestSyncDoesntUpdateModtime run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-yovulez1buxa'", Local "Local file system at /tmp/rclone771422369", Modify Window "1ms" 2025/04/30 16:54:24 DEBUG : foo: md5 = 3bf48a42e5214db97eda0f29a6b35229 OK 2025/04/30 16:54:25 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yovulez1buxa': Waiting for checks to finish 2025/04/30 16:54:25 DEBUG : foo: Modification times differ by -95456h54m52.624456789s: 2011-12-25 12:59:59.123456789 +0000 UTC, 2001-02-03 04:05:06.499 +0000 UTC 2025/04/30 16:54:25 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yovulez1buxa': Waiting for transfers to finish 2025/04/30 16:54:26 DEBUG : foo: md5 = 6b9c62084bf3f3415f873f28de8d9abf OK 2025/04/30 16:54:26 INFO : foo: Copied (replaced existing) 2025/04/30 16:54:26 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-yovulez1buxa'", Local "Local file system at /tmp/rclone771422369", Modify Window "1ms" --- PASS: TestSyncDoesntUpdateModtime (5.31s) === RUN TestSyncAfterAddingAFile run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-yovulez1buxa'", Local "Local file system at /tmp/rclone771422369", Modify Window "1ms" 2025/04/30 16:54:29 DEBUG : empty space: md5 = 5c09380d8135f7af5a607668e1fe5080 OK 2025/04/30 16:54:30 DEBUG : potato: Need to transfer - File not found at Destination 2025/04/30 16:54:30 DEBUG : empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/04/30 16:54:30 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yovulez1buxa': Waiting for checks to finish 2025/04/30 16:54:30 DEBUG : empty space: Unchanged skipping 2025/04/30 16:54:30 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yovulez1buxa': Waiting for transfers to finish 2025/04/30 16:54:31 DEBUG : potato: md5 = 507676d47d6cc19781f353fa3ef20334 OK 2025/04/30 16:54:31 INFO : potato: Copied (new) 2025/04/30 16:54:31 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-yovulez1buxa'", Local "Local file system at /tmp/rclone771422369", Modify Window "1ms" --- PASS: TestSyncAfterAddingAFile (5.56s) === RUN TestSyncAfterChangingFilesSizeOnly run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-yovulez1buxa'", Local "Local file system at /tmp/rclone771422369", Modify Window "1ms" 2025/04/30 16:54:35 DEBUG : potato: md5 = b4522cb08c924d7c59df0deab964566a OK 2025/04/30 16:54:35 DEBUG : potato: Sizes differ (src 21 vs dst 60) 2025/04/30 16:54:35 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yovulez1buxa': Waiting for checks to finish 2025/04/30 16:54:35 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yovulez1buxa': Waiting for transfers to finish 2025/04/30 16:54:37 DEBUG : potato: md5 = 529debd477f5fdc8ab421f1578ee9b1a OK 2025/04/30 16:54:37 INFO : potato: Copied (replaced existing) 2025/04/30 16:54:37 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-yovulez1buxa'", Local "Local file system at /tmp/rclone771422369", Modify Window "1ms" --- PASS: TestSyncAfterChangingFilesSizeOnly (4.73s) === RUN TestSyncAfterChangingContentsOnly run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-yovulez1buxa'", Local "Local file system at /tmp/rclone771422369", Modify Window "1ms" 2025/04/30 16:54:40 DEBUG : potato: md5 = 1b9bb624b560cc2e374c644da5328c9f OK 2025/04/30 16:54:40 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yovulez1buxa': Waiting for checks to finish 2025/04/30 16:54:40 DEBUG : potato: Modification times differ by 119h59m59.876543211s: 2011-12-25 12:59:59.123456789 +0000 UTC, 2011-12-30 12:59:59 +0000 UTC 2025/04/30 16:54:40 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yovulez1buxa': Waiting for transfers to finish 2025/04/30 16:54:41 DEBUG : potato: md5 = d7c58a4642f4bdcfb315873f686cd216 OK 2025/04/30 16:54:41 INFO : potato: Copied (replaced existing) 2025/04/30 16:54:41 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-yovulez1buxa'", Local "Local file system at /tmp/rclone771422369", Modify Window "1ms" --- PASS: TestSyncAfterChangingContentsOnly (4.77s) === RUN TestSyncAfterRemovingAFileAndAddingAFileDryRun run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-yovulez1buxa'", Local "Local file system at /tmp/rclone771422369", Modify Window "1ms" 2025/04/30 16:54:45 DEBUG : potato: md5 = 845db9ca86d333ea6b8fa9ffa77857ee OK 2025/04/30 16:54:46 DEBUG : empty space: md5 = 6a823da52be537684465de05defa712e OK 2025/04/30 16:54:46 DEBUG : potato2: Need to transfer - File not found at Destination 2025/04/30 16:54:46 NOTICE: potato2: Skipped copy as --dry-run is set (size 60) 2025/04/30 16:54:46 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yovulez1buxa': Waiting for checks to finish 2025/04/30 16:54:46 DEBUG : empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/04/30 16:54:46 DEBUG : empty space: Unchanged skipping 2025/04/30 16:54:46 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yovulez1buxa': Waiting for transfers to finish 2025/04/30 16:54:46 DEBUG : Waiting for deletions to finish 2025/04/30 16:54:46 NOTICE: potato: Skipped delete as --dry-run is set (size 21) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-yovulez1buxa'", Local "Local file system at /tmp/rclone771422369", Modify Window "1ms" --- PASS: TestSyncAfterRemovingAFileAndAddingAFileDryRun (5.37s) === RUN TestSyncAfterRemovingAFileAndAddingAFile run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-yovulez1buxa'", Local "Local file system at /tmp/rclone771422369", Modify Window "1ms" 2025/04/30 16:54:50 DEBUG : potato: md5 = 46bc18918b729561b6a866b984930960 OK 2025/04/30 16:54:51 DEBUG : empty space: md5 = c9921ba07bc8e0ae9c78cba3496401aa OK 2025/04/30 16:54:52 DEBUG : potato2: Need to transfer - File not found at Destination 2025/04/30 16:54:52 DEBUG : empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/04/30 16:54:52 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yovulez1buxa': Waiting for checks to finish 2025/04/30 16:54:52 DEBUG : empty space: Unchanged skipping 2025/04/30 16:54:52 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yovulez1buxa': Waiting for transfers to finish 2025/04/30 16:54:53 DEBUG : potato2: md5 = 64563a1fe728a2b039772f3d22bf8d9f OK 2025/04/30 16:54:53 INFO : potato2: Copied (new) 2025/04/30 16:54:53 DEBUG : Waiting for deletions to finish 2025/04/30 16:54:54 INFO : potato: Deleted run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-yovulez1buxa'", Local "Local file system at /tmp/rclone771422369", Modify Window "1ms" --- PASS: TestSyncAfterRemovingAFileAndAddingAFile (7.50s) === RUN TestSyncAfterRemovingAFileAndAddingAFileSubDir run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-yovulez1buxa'", Local "Local file system at /tmp/rclone771422369", Modify Window "1ms" 2025/04/30 16:54:58 DEBUG : b/potato: md5 = 8770b375c35c3f8f8784ede8064c8aef OK 2025/04/30 16:55:01 DEBUG : c/non empty space: md5 = 06bb2394a87fb1477ea355a7ca7e074b OK 2025/04/30 16:55:01 INFO : d: Making directory 2025/04/30 16:55:01 INFO : d/e: Making directory 2025/04/30 16:55:03 DEBUG : Added delayed dir = "a", newDst= 2025/04/30 16:55:04 INFO : c: Set directory modification time (using SetModTime) 2025/04/30 16:55:04 DEBUG : Added delayed dir = "c", newDst=c 2025/04/30 16:55:04 DEBUG : a/potato2: Need to transfer - File not found at Destination 2025/04/30 16:55:04 DEBUG : c/non empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/04/30 16:55:04 DEBUG : c/non empty space: Unchanged skipping 2025/04/30 16:55:05 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yovulez1buxa': Waiting for checks to finish 2025/04/30 16:55:05 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yovulez1buxa': Waiting for transfers to finish 2025/04/30 16:55:06 DEBUG : a/potato2: md5 = a7783cfe25e00d5201f360b24787d9d9 OK 2025/04/30 16:55:06 INFO : a/potato2: Copied (new) 2025/04/30 16:55:06 DEBUG : Waiting for deletions to finish 2025/04/30 16:55:07 INFO : b/potato: Deleted 2025/04/30 16:55:07 INFO : a: Set directory modification time (using DirSetModTime) 2025/04/30 16:55:07 INFO : d/e: Removing directory 2025/04/30 16:55:08 INFO : d: Removing directory 2025/04/30 16:55:08 DEBUG : ka6id8d20d3s5ktapedlphgta8: Rmdir: contains trashed file: "r8sppajuabeak3sbgj2ak8vuf8" 2025/04/30 16:55:09 INFO : b: Removing directory 2025/04/30 16:55:09 DEBUG : 32d8ua6196mc1r7qkfog53rkg0: Rmdir: contains trashed file: "2m507n64kafsi59v9q71r281a4" 2025/04/30 16:55:09 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yovulez1buxa': deleted 3 directories run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-yovulez1buxa'", Local "Local file system at /tmp/rclone771422369", Modify Window "1ms" 2025/04/30 16:55:12 DEBUG : 3i9du405pfogq3ncai6pg7ouio: Rmdir: contains trashed file: "982d3pss7t5pn0il16r2foj31s" 2025/04/30 16:55:12 DEBUG : 2bsvlrk2ne1lfitm6tttcu0qt8: Rmdir: contains trashed file: "89l8renevh3mji1c8r1p7qn6tg" --- PASS: TestSyncAfterRemovingAFileAndAddingAFileSubDir (17.61s) === RUN TestSyncAfterRemovingAFileAndAddingAFileSubDirWithErrors run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-yovulez1buxa'", Local "Local file system at /tmp/rclone771422369", Modify Window "1ms" 2025/04/30 16:55:16 DEBUG : b/potato: md5 = 4ba08450480fc52f7dcacbd147803c9c OK 2025/04/30 16:55:18 DEBUG : c/non empty space: md5 = a35376383882b468394aabea846bee4a OK 2025/04/30 16:55:18 INFO : d: Making directory 2025/04/30 16:55:20 DEBUG : Added delayed dir = "a", newDst= 2025/04/30 16:55:20 INFO : c: Set directory modification time (using SetModTime) 2025/04/30 16:55:20 DEBUG : Added delayed dir = "c", newDst=c 2025/04/30 16:55:20 DEBUG : a/potato2: Need to transfer - File not found at Destination 2025/04/30 16:55:20 DEBUG : c/non empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/04/30 16:55:20 DEBUG : c/non empty space: Unchanged skipping 2025/04/30 16:55:20 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yovulez1buxa': Waiting for checks to finish 2025/04/30 16:55:20 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yovulez1buxa': Waiting for transfers to finish 2025/04/30 16:55:23 DEBUG : a/potato2: md5 = 37c761a3102f938c780f26d5cff909f6 OK 2025/04/30 16:55:23 INFO : a/potato2: Copied (new) 2025/04/30 16:55:23 ERROR : Encrypted drive 'TestCryptDrive:rclone-test-yovulez1buxa': not deleting files as there were IO errors 2025/04/30 16:55:23 INFO : a: Set directory modification time (using DirSetModTime) 2025/04/30 16:55:23 ERROR : Encrypted drive 'TestCryptDrive:rclone-test-yovulez1buxa': not deleting directories as there were IO errors run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-yovulez1buxa'", Local "Local file system at /tmp/rclone771422369", Modify Window "1ms" 2025/04/30 16:55:27 DEBUG : 3i9du405pfogq3ncai6pg7ouio: Rmdir: contains trashed file: "982d3pss7t5pn0il16r2foj31s" 2025/04/30 16:55:27 DEBUG : 32d8ua6196mc1r7qkfog53rkg0: Rmdir: contains trashed file: "2m507n64kafsi59v9q71r281a4" 2025/04/30 16:55:28 DEBUG : 2bsvlrk2ne1lfitm6tttcu0qt8: Rmdir: contains trashed file: "89l8renevh3mji1c8r1p7qn6tg" --- PASS: TestSyncAfterRemovingAFileAndAddingAFileSubDirWithErrors (15.99s) === RUN TestSyncDeleteAfter --- PASS: TestSyncDeleteAfter (0.00s) === RUN TestSyncDeleteDuring run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-yovulez1buxa'", Local "Local file system at /tmp/rclone771422369", Modify Window "1ms" 2025/04/30 16:55:31 DEBUG : potato: md5 = 9078dba6f8a7c30e2de17067a111eeba OK 2025/04/30 16:55:33 DEBUG : empty space: md5 = a512074c653aed900a12e6cf5eadf1fb OK 2025/04/30 16:55:33 DEBUG : Waiting for deletions to finish 2025/04/30 16:55:33 DEBUG : potato2: Need to transfer - File not found at Destination 2025/04/30 16:55:33 DEBUG : empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/04/30 16:55:33 DEBUG : empty space: Unchanged skipping 2025/04/30 16:55:33 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yovulez1buxa': Waiting for checks to finish 2025/04/30 16:55:33 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yovulez1buxa': Waiting for transfers to finish 2025/04/30 16:55:34 INFO : potato: Deleted 2025/04/30 16:55:35 DEBUG : potato2: md5 = a57840edb7b3edec25f30040e82a23c1 OK 2025/04/30 16:55:35 INFO : potato2: Copied (new) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-yovulez1buxa'", Local "Local file system at /tmp/rclone771422369", Modify Window "1ms" --- PASS: TestSyncDeleteDuring (7.40s) === RUN TestSyncDeleteBefore run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-yovulez1buxa'", Local "Local file system at /tmp/rclone771422369", Modify Window "1ms" 2025/04/30 16:55:38 DEBUG : potato: md5 = 3155166c37964e801411154fd4cf557c OK 2025/04/30 16:55:40 DEBUG : empty space: md5 = f94c824b7147f145d458d739663000de OK 2025/04/30 16:55:40 DEBUG : Waiting for deletions to finish 2025/04/30 16:55:40 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yovulez1buxa': Waiting for checks to finish 2025/04/30 16:55:40 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yovulez1buxa': Waiting for transfers to finish 2025/04/30 16:55:41 INFO : potato: Deleted 2025/04/30 16:55:41 DEBUG : potato2: Need to transfer - File not found at Destination 2025/04/30 16:55:41 DEBUG : empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/04/30 16:55:41 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yovulez1buxa': Waiting for checks to finish 2025/04/30 16:55:41 DEBUG : empty space: Unchanged skipping 2025/04/30 16:55:41 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yovulez1buxa': Waiting for transfers to finish 2025/04/30 16:55:43 DEBUG : potato2: md5 = 239b930e0f8842b28e5fc533572e56ab OK 2025/04/30 16:55:43 INFO : potato2: Copied (new) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-yovulez1buxa'", Local "Local file system at /tmp/rclone771422369", Modify Window "1ms" --- PASS: TestSyncDeleteBefore (7.99s) === RUN TestCopyDeleteBefore run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-yovulez1buxa'", Local "Local file system at /tmp/rclone771422369", Modify Window "1ms" 2025/04/30 16:55:46 DEBUG : potato: md5 = e961ad9147e077216524ea25ad653da5 OK 2025/04/30 16:55:47 DEBUG : potato2: Need to transfer - File not found at Destination 2025/04/30 16:55:47 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yovulez1buxa': Waiting for checks to finish 2025/04/30 16:55:47 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yovulez1buxa': Waiting for transfers to finish 2025/04/30 16:55:48 DEBUG : potato2: md5 = 1160db0d62122ed734554401df725b8e OK 2025/04/30 16:55:48 INFO : potato2: Copied (new) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-yovulez1buxa'", Local "Local file system at /tmp/rclone771422369", Modify Window "1ms" --- PASS: TestCopyDeleteBefore (5.46s) === RUN TestSyncWithExclude run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-yovulez1buxa'", Local "Local file system at /tmp/rclone771422369", Modify Window "1ms" 2025/04/30 16:55:52 DEBUG : potato2: md5 = f411e06367d8c0757d6c05ab1f848b1f OK 2025/04/30 16:55:54 DEBUG : empty space: md5 = bd0fabac32687395d1b9abac71df1d14 OK 2025/04/30 16:55:54 DEBUG : enormous: Excluded (Size Filter) 2025/04/30 16:55:54 DEBUG : enormous: Excluded 2025/04/30 16:55:54 DEBUG : potato2: Excluded (Size Filter) 2025/04/30 16:55:54 DEBUG : potato2: Excluded 2025/04/30 16:55:54 DEBUG : potato2: Excluded (Size Filter) 2025/04/30 16:55:54 DEBUG : potato2: Excluded 2025/04/30 16:55:54 DEBUG : empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/04/30 16:55:54 DEBUG : empty space: Unchanged skipping 2025/04/30 16:55:54 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yovulez1buxa': Waiting for checks to finish 2025/04/30 16:55:54 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yovulez1buxa': Waiting for transfers to finish 2025/04/30 16:55:54 DEBUG : Waiting for deletions to finish 2025/04/30 16:55:54 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-yovulez1buxa'", Local "Local file system at /tmp/rclone771422369", Modify Window "1ms" 2025/04/30 16:55:54 DEBUG : enormous: Excluded (Size Filter) 2025/04/30 16:55:54 DEBUG : enormous: Excluded 2025/04/30 16:55:54 DEBUG : potato2: Excluded (Size Filter) 2025/04/30 16:55:54 DEBUG : potato2: Excluded 2025/04/30 16:55:55 DEBUG : potato2: Excluded (Size Filter) 2025/04/30 16:55:55 DEBUG : potato2: Excluded 2025/04/30 16:55:55 DEBUG : empty space: Size and modification time the same (differ by 456.789µs, within tolerance 1ms) 2025/04/30 16:55:55 DEBUG : empty space: Unchanged skipping 2025/04/30 16:55:55 DEBUG : Local file system at /tmp/rclone771422369: Waiting for checks to finish 2025/04/30 16:55:55 DEBUG : Local file system at /tmp/rclone771422369: Waiting for transfers to finish 2025/04/30 16:55:55 DEBUG : Waiting for deletions to finish 2025/04/30 16:55:55 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-yovulez1buxa'", Local "Local file system at /tmp/rclone771422369", Modify Window "1ms" --- PASS: TestSyncWithExclude (6.83s) === RUN TestSyncWithExcludeAndDeleteExcluded run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-yovulez1buxa'", Local "Local file system at /tmp/rclone771422369", Modify Window "1ms" 2025/04/30 16:55:59 DEBUG : potato2: md5 = 6c9c35fac91519835ecc843d88920c47 OK 2025/04/30 16:56:00 DEBUG : empty space: md5 = 3a6ad015d6f06ef18601e3bdc0012f03 OK 2025/04/30 16:56:01 DEBUG : enormous: md5 = 0ef9d484bd3afba9ec1a3e7198e2c97c OK 2025/04/30 16:56:02 DEBUG : enormous: Excluded (Size Filter) 2025/04/30 16:56:02 DEBUG : enormous: Excluded 2025/04/30 16:56:02 DEBUG : potato2: Excluded (Size Filter) 2025/04/30 16:56:02 DEBUG : potato2: Excluded 2025/04/30 16:56:02 DEBUG : empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/04/30 16:56:02 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yovulez1buxa': Waiting for checks to finish 2025/04/30 16:56:02 DEBUG : empty space: Unchanged skipping 2025/04/30 16:56:02 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yovulez1buxa': Waiting for transfers to finish 2025/04/30 16:56:02 DEBUG : Waiting for deletions to finish 2025/04/30 16:56:02 INFO : enormous: Deleted 2025/04/30 16:56:02 INFO : potato2: Deleted 2025/04/30 16:56:02 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-yovulez1buxa'", Local "Local file system at /tmp/rclone771422369", Modify Window "1ms" 2025/04/30 16:56:03 DEBUG : empty space: Size and modification time the same (differ by 456.789µs, within tolerance 1ms) 2025/04/30 16:56:03 DEBUG : empty space: Unchanged skipping 2025/04/30 16:56:03 DEBUG : Local file system at /tmp/rclone771422369: Waiting for checks to finish 2025/04/30 16:56:03 DEBUG : Local file system at /tmp/rclone771422369: Waiting for transfers to finish 2025/04/30 16:56:03 DEBUG : Waiting for deletions to finish 2025/04/30 16:56:03 INFO : enormous: Deleted 2025/04/30 16:56:03 INFO : potato2: Deleted 2025/04/30 16:56:03 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-yovulez1buxa'", Local "Local file system at /tmp/rclone771422369", Modify Window "1ms" --- PASS: TestSyncWithExcludeAndDeleteExcluded (7.75s) === RUN TestSyncWithUpdateOlder run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-yovulez1buxa'", Local "Local file system at /tmp/rclone771422369", Modify Window "1ms" 2025/04/30 16:56:06 DEBUG : one: md5 = 2e54517a347474659b57c109d0f744d6 OK 2025/04/30 16:56:08 DEBUG : two: md5 = e8a16829960c93a2df50116c30d96c7a OK 2025/04/30 16:56:09 DEBUG : three: md5 = 38bf01bebcf199670ef7f963e6956545 OK 2025/04/30 16:56:11 DEBUG : four: md5 = 61a8dcc4f17aad03faac5ab5b607c0cf OK 2025/04/30 16:56:12 DEBUG : five: Need to transfer - File not found at Destination 2025/04/30 16:56:12 DEBUG : four: Sizes differ (src 4 vs dst 8) 2025/04/30 16:56:12 DEBUG : one: Destination is newer than source, skipping 2025/04/30 16:56:12 DEBUG : three: Sizes identical 2025/04/30 16:56:12 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yovulez1buxa': Waiting for checks to finish 2025/04/30 16:56:12 DEBUG : four: Destination mod time is within 1s of source but files differ, transferring 2025/04/30 16:56:12 DEBUG : three: Destination mod time is within 1s of source and files identical, skipping 2025/04/30 16:56:12 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yovulez1buxa': Waiting for transfers to finish 2025/04/30 16:56:13 DEBUG : four: md5 = 0a001b438b9f500072da7dc0946935a6 OK 2025/04/30 16:56:13 INFO : four: Copied (replaced existing) 2025/04/30 16:56:13 DEBUG : two: md5 = d71de8a67df1c38225e1ca4cc0578b89 OK 2025/04/30 16:56:13 INFO : two: Copied (replaced existing) 2025/04/30 16:56:13 DEBUG : five: md5 = 834ee41520ad3d20911906893e3c6675 OK 2025/04/30 16:56:13 INFO : five: Copied (new) 2025/04/30 16:56:13 DEBUG : Waiting for deletions to finish sync_test.go:1449: Skip test with --checksum as no hashes supported --- PASS: TestSyncWithUpdateOlder (11.60s) === 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-yovulez1buxa'", Local "Local file system at /tmp/rclone771422369", Modify Window "1ms" sync_test.go:1538: Can track renames: false 2025/04/30 16:56:17 ERROR : Encrypted drive 'TestCryptDrive:rclone-test-yovulez1buxa': Ignoring --track-renames as the source and destination do not have a common hash 2025/04/30 16:56:17 DEBUG : potato: Need to transfer - File not found at Destination 2025/04/30 16:56:17 DEBUG : yam: Need to transfer - File not found at Destination 2025/04/30 16:56:17 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yovulez1buxa': Waiting for checks to finish 2025/04/30 16:56:17 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yovulez1buxa': Waiting for transfers to finish 2025/04/30 16:56:18 DEBUG : potato: md5 = 01d929439234ef7239a51451139708c6 OK 2025/04/30 16:56:18 INFO : potato: Copied (new) 2025/04/30 16:56:18 DEBUG : yam: md5 = 79329c70a6a089f9a03fb8ba8403daf7 OK 2025/04/30 16:56:18 INFO : yam: Copied (new) 2025/04/30 16:56:18 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-yovulez1buxa'", Local "Local file system at /tmp/rclone771422369", Modify Window "1ms" 2025/04/30 16:56:18 ERROR : Encrypted drive 'TestCryptDrive:rclone-test-yovulez1buxa': Ignoring --track-renames as the source and destination do not have a common hash 2025/04/30 16:56:19 DEBUG : yaml: Need to transfer - File not found at Destination 2025/04/30 16:56:19 DEBUG : potato: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/30 16:56:19 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yovulez1buxa': Waiting for checks to finish 2025/04/30 16:56:19 DEBUG : potato: Unchanged skipping 2025/04/30 16:56:19 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yovulez1buxa': Waiting for transfers to finish 2025/04/30 16:56:20 DEBUG : yaml: md5 = 5ce5e4c94057bb14771aa2ebac97555e OK 2025/04/30 16:56:20 INFO : yaml: Copied (new) 2025/04/30 16:56:20 DEBUG : Waiting for deletions to finish 2025/04/30 16:56:21 INFO : yam: Deleted run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-yovulez1buxa'", Local "Local file system at /tmp/rclone771422369", Modify Window "1ms" --- PASS: TestSyncWithTrackRenames (6.97s) === RUN TestParseRenamesStrategyModtime --- PASS: TestParseRenamesStrategyModtime (0.00s) === RUN TestRenamesStrategyModtime --- PASS: TestRenamesStrategyModtime (0.00s) === RUN TestSyncWithTrackRenamesStrategyModtime run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-yovulez1buxa'", Local "Local file system at /tmp/rclone771422369", Modify Window "1ms" sync_test.go:1610: Can track renames: true 2025/04/30 16:56:24 INFO : Encrypted drive 'TestCryptDrive:rclone-test-yovulez1buxa': Making map for --track-renames 2025/04/30 16:56:24 INFO : Encrypted drive 'TestCryptDrive:rclone-test-yovulez1buxa': Finished making map for --track-renames 2025/04/30 16:56:24 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yovulez1buxa': Waiting for checks to finish 2025/04/30 16:56:24 DEBUG : potato: Need to transfer - No matching file found at Destination 2025/04/30 16:56:24 DEBUG : yam: Need to transfer - No matching file found at Destination 2025/04/30 16:56:24 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yovulez1buxa': Waiting for renames to finish 2025/04/30 16:56:24 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yovulez1buxa': Waiting for transfers to finish 2025/04/30 16:56:25 DEBUG : potato: md5 = 87087236de22d241762744b3c89983d2 OK 2025/04/30 16:56:25 INFO : potato: Copied (new) 2025/04/30 16:56:25 DEBUG : yam: md5 = 8a67e4f10915cb962179e46c55cb0763 OK 2025/04/30 16:56:25 INFO : yam: Copied (new) 2025/04/30 16:56:25 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-yovulez1buxa'", Local "Local file system at /tmp/rclone771422369", Modify Window "1ms" 2025/04/30 16:56:26 DEBUG : potato: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/30 16:56:26 INFO : Encrypted drive 'TestCryptDrive:rclone-test-yovulez1buxa': Making map for --track-renames 2025/04/30 16:56:26 INFO : Encrypted drive 'TestCryptDrive:rclone-test-yovulez1buxa': Finished making map for --track-renames 2025/04/30 16:56:26 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yovulez1buxa': Waiting for checks to finish 2025/04/30 16:56:26 DEBUG : potato: Unchanged skipping 2025/04/30 16:56:26 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yovulez1buxa': Waiting for renames to finish 2025/04/30 16:56:27 INFO : yam: Moved (server-side) to: yaml 2025/04/30 16:56:27 INFO : yaml: Renamed from "yam" 2025/04/30 16:56:27 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yovulez1buxa': Waiting for transfers to finish 2025/04/30 16:56:27 DEBUG : Waiting for deletions to finish 2025/04/30 16:56:27 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-yovulez1buxa'", Local "Local file system at /tmp/rclone771422369", Modify Window "1ms" --- PASS: TestSyncWithTrackRenamesStrategyModtime (5.83s) === RUN TestSyncWithTrackRenamesStrategyLeaf run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-yovulez1buxa'", Local "Local file system at /tmp/rclone771422369", Modify Window "1ms" sync_test.go:1649: Can track renames: true 2025/04/30 16:56:30 DEBUG : Added delayed dir = "sub", newDst= 2025/04/30 16:56:30 INFO : Encrypted drive 'TestCryptDrive:rclone-test-yovulez1buxa': Making map for --track-renames 2025/04/30 16:56:30 INFO : Encrypted drive 'TestCryptDrive:rclone-test-yovulez1buxa': Finished making map for --track-renames 2025/04/30 16:56:30 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yovulez1buxa': Waiting for checks to finish 2025/04/30 16:56:30 DEBUG : potato: Need to transfer - No matching file found at Destination 2025/04/30 16:56:30 DEBUG : sub/yam: Need to transfer - No matching file found at Destination 2025/04/30 16:56:30 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yovulez1buxa': Waiting for renames to finish 2025/04/30 16:56:30 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yovulez1buxa': Waiting for transfers to finish 2025/04/30 16:56:32 DEBUG : potato: md5 = fcb3cfc4b51365436c4c7c1db158d76d OK 2025/04/30 16:56:32 INFO : potato: Copied (new) 2025/04/30 16:56:32 DEBUG : sub/yam: md5 = 775a49c9ec69533c425f884fd12bf829 OK 2025/04/30 16:56:32 INFO : sub/yam: Copied (new) 2025/04/30 16:56:32 DEBUG : Waiting for deletions to finish 2025/04/30 16:56:33 INFO : sub: Set directory modification time (using DirSetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-yovulez1buxa'", Local "Local file system at /tmp/rclone771422369", Modify Window "1ms" 2025/04/30 16:56:33 DEBUG : potato: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/30 16:56:33 DEBUG : potato: Unchanged skipping 2025/04/30 16:56:34 INFO : sub: Set directory modification time (using SetModTime) 2025/04/30 16:56:34 DEBUG : Added delayed dir = "sub", newDst=sub 2025/04/30 16:56:34 INFO : Encrypted drive 'TestCryptDrive:rclone-test-yovulez1buxa': Making map for --track-renames 2025/04/30 16:56:34 INFO : Encrypted drive 'TestCryptDrive:rclone-test-yovulez1buxa': Finished making map for --track-renames 2025/04/30 16:56:34 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yovulez1buxa': Waiting for checks to finish 2025/04/30 16:56:34 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yovulez1buxa': Waiting for renames to finish 2025/04/30 16:56:35 INFO : sub/yam: Moved (server-side) to: yam 2025/04/30 16:56:35 INFO : yam: Renamed from "sub/yam" 2025/04/30 16:56:35 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yovulez1buxa': Waiting for transfers to finish 2025/04/30 16:56:35 DEBUG : Waiting for deletions to finish 2025/04/30 16:56:35 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-yovulez1buxa'", Local "Local file system at /tmp/rclone771422369", Modify Window "1ms" --- PASS: TestSyncWithTrackRenamesStrategyLeaf (9.43s) === RUN TestServerSideMoveLocal run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-yovulez1buxa'", Local "Local file system at /tmp/rclone771422369", Modify Window "1ms" 2025/04/30 16:56:39 DEBUG : Creating backend with remote "/tmp/rclone771422369/dir1" 2025/04/30 16:56:39 DEBUG : Config file has changed externally - reloading 2025/04/30 16:56:39 DEBUG : Creating backend with remote "/tmp/rclone771422369/dir2" 2025/04/30 16:56:39 DEBUG : Local file system at /tmp/rclone771422369/dir2: Using server-side directory move 2025/04/30 16:56:39 INFO : Local file system at /tmp/rclone771422369/dir2: Server side directory move failed - fallback to file moves: can't copy directory - destination already exists 2025/04/30 16:56:39 DEBUG : file1.txt: Need to transfer - File not found at Destination 2025/04/30 16:56:39 INFO : file1.txt: Moved (server-side) 2025/04/30 16:56:39 DEBUG : Local file system at /tmp/rclone771422369/dir2: Waiting for checks to finish 2025/04/30 16:56:39 DEBUG : Local file system at /tmp/rclone771422369/dir2: Waiting for transfers to finish --- PASS: TestServerSideMoveLocal (0.43s) === RUN TestMoveWithDeleteEmptySrcDirs run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-yovulez1buxa'", Local "Local file system at /tmp/rclone771422369", Modify Window "1ms" 2025/04/30 16:56:39 DEBUG : Added delayed dir = "nested", newDst= 2025/04/30 16:56:39 DEBUG : Added delayed dir = "sub dir", newDst= 2025/04/30 16:56:39 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2025/04/30 16:56:39 DEBUG : Added delayed dir = "nested/sub dir", newDst= 2025/04/30 16:56:39 DEBUG : nested/sub dir/file: Need to transfer - File not found at Destination 2025/04/30 16:56:39 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yovulez1buxa': Waiting for checks to finish 2025/04/30 16:56:39 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yovulez1buxa': Waiting for transfers to finish 2025/04/30 16:56:42 DEBUG : sub dir/hello world: md5 = 2e8627a164a0b7e77fe874152e337fd6 OK 2025/04/30 16:56:42 INFO : sub dir/hello world: Copied (new) 2025/04/30 16:56:42 INFO : sub dir/hello world: Deleted 2025/04/30 16:56:44 DEBUG : nested/sub dir/file: md5 = acbd3656aaa88e57ad70675e44c8a483 OK 2025/04/30 16:56:44 INFO : nested/sub dir/file: Copied (new) 2025/04/30 16:56:44 INFO : nested/sub dir/file: Deleted 2025/04/30 16:56:44 INFO : nested/sub dir: Set directory modification time (using DirSetModTime) 2025/04/30 16:56:44 INFO : nested: Set directory modification time (using DirSetModTime) 2025/04/30 16:56:45 INFO : sub dir: Set directory modification time (using DirSetModTime) 2025/04/30 16:56:45 INFO : sub dir: Removing directory 2025/04/30 16:56:45 INFO : nested/sub dir: Removing directory 2025/04/30 16:56:45 INFO : nested: Removing directory 2025/04/30 16:56:45 DEBUG : Local file system at /tmp/rclone771422369: deleted 3 directories run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-yovulez1buxa'", Local "Local file system at /tmp/rclone771422369", Modify Window "1ms" 2025/04/30 16:56:48 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" 2025/04/30 16:56:48 DEBUG : 37qp6d1gohacv723ij3brofbu8/14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "ftp4kuv8se7tqduu6pmmcvjsmk" 2025/04/30 16:56:49 DEBUG : 37qp6d1gohacv723ij3brofbu8: Rmdir: contains trashed file: "14begaa36ih249fgrnfk6nulg0" --- PASS: TestMoveWithDeleteEmptySrcDirs (11.03s) === RUN TestMoveWithoutDeleteEmptySrcDirs run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-yovulez1buxa'", Local "Local file system at /tmp/rclone771422369", Modify Window "1ms" 2025/04/30 16:56:50 DEBUG : Added delayed dir = "nested", newDst= 2025/04/30 16:56:50 DEBUG : Added delayed dir = "sub dir", newDst= 2025/04/30 16:56:50 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2025/04/30 16:56:50 DEBUG : Added delayed dir = "nested/sub dir", newDst= 2025/04/30 16:56:50 DEBUG : nested/sub dir/file: Need to transfer - File not found at Destination 2025/04/30 16:56:50 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yovulez1buxa': Waiting for checks to finish 2025/04/30 16:56:50 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yovulez1buxa': Waiting for transfers to finish 2025/04/30 16:56:53 DEBUG : sub dir/hello world: md5 = c3d39ddbbce0ba9c5c1520fa4a558b90 OK 2025/04/30 16:56:53 INFO : sub dir/hello world: Copied (new) 2025/04/30 16:56:53 INFO : sub dir/hello world: Deleted 2025/04/30 16:56:55 DEBUG : nested/sub dir/file: md5 = cd24f7cd190fd2f92f881baf8614e131 OK 2025/04/30 16:56:55 INFO : nested/sub dir/file: Copied (new) 2025/04/30 16:56:55 INFO : nested/sub dir/file: Deleted 2025/04/30 16:56:55 INFO : nested/sub dir: Set directory modification time (using DirSetModTime) 2025/04/30 16:56:56 INFO : sub dir: Set directory modification time (using DirSetModTime) 2025/04/30 16:56:56 INFO : nested: Set directory modification time (using DirSetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-yovulez1buxa'", Local "Local file system at /tmp/rclone771422369", Modify Window "1ms" 2025/04/30 16:56:58 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" 2025/04/30 16:56:59 DEBUG : 37qp6d1gohacv723ij3brofbu8/14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "ftp4kuv8se7tqduu6pmmcvjsmk" 2025/04/30 16:57:00 DEBUG : 37qp6d1gohacv723ij3brofbu8: Rmdir: contains trashed file: "14begaa36ih249fgrnfk6nulg0" --- PASS: TestMoveWithoutDeleteEmptySrcDirs (10.90s) === RUN TestMoveWithIgnoreExisting run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-yovulez1buxa'", Local "Local file system at /tmp/rclone771422369", Modify Window "1ms" 2025/04/30 16:57:01 DEBUG : existing: Need to transfer - File not found at Destination 2025/04/30 16:57:01 DEBUG : existing-b: Need to transfer - File not found at Destination 2025/04/30 16:57:01 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yovulez1buxa': Waiting for checks to finish 2025/04/30 16:57:01 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yovulez1buxa': Waiting for transfers to finish 2025/04/30 16:57:03 DEBUG : existing: md5 = cac289328edc89931f4638176d05fd50 OK 2025/04/30 16:57:03 INFO : existing: Copied (new) 2025/04/30 16:57:03 INFO : existing: Deleted 2025/04/30 16:57:03 DEBUG : existing-b: md5 = b185b9b4a33b20d7e44f2b3ce1fe56af OK 2025/04/30 16:57:03 INFO : existing-b: Copied (new) 2025/04/30 16:57:03 INFO : existing-b: Deleted 2025/04/30 16:57:03 DEBUG : existing: Destination exists, skipping 2025/04/30 16:57:03 DEBUG : existing: Not removing source file as destination file exists and --ignore-existing is set 2025/04/30 16:57:03 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yovulez1buxa': Waiting for checks to finish 2025/04/30 16:57:03 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yovulez1buxa': Waiting for transfers to finish 2025/04/30 16:57:03 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-yovulez1buxa'", Local "Local file system at /tmp/rclone771422369", Modify Window "1ms" --- PASS: TestMoveWithIgnoreExisting (4.40s) === RUN TestServerSideMove run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-yovulez1buxa'", Local "Local file system at /tmp/rclone771422369", Modify Window "1ms" 2025/04/30 16:57:06 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-motasih5cadi" 2025/04/30 16:57:06 DEBUG : Creating backend with remote "TestDrive:crypt/709a0v4rb8a7dtq743jsn13rfocq3g9u3ov0hsqi18653lk2usng" 2025/04/30 16:57:08 DEBUG : potato2: md5 = 6a677cc42b7feecaa59d64c7585f168f OK 2025/04/30 16:57:10 DEBUG : empty space: md5 = 7b24521c85afcf227e202526a4be5923 OK 2025/04/30 16:57:11 DEBUG : potato3: md5 = 0743b6a4f6a010b852551796d03443e7 OK sync_test.go:1705: Server side move (if possible) Encrypted drive 'TestCryptDrive:rclone-test-yovulez1buxa' -> Encrypted drive 'TestCryptDrive:rclone-test-motasih5cadi' 2025/04/30 16:57:14 DEBUG : empty space: md5 = c76f5873fa04252f7bf6c919a85472bc OK 2025/04/30 16:57:15 DEBUG : potato3: md5 = 40c13e53540f69a2093a993f7a7723ab OK 2025/04/30 16:57:15 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-motasih5cadi': Using server-side directory move 2025/04/30 16:57:15 INFO : Encrypted drive 'TestCryptDrive:rclone-test-motasih5cadi': Server side directory move failed - fallback to file moves: can't copy directory - destination already exists 2025/04/30 16:57:16 DEBUG : potato2: Need to transfer - File not found at Destination 2025/04/30 16:57:16 DEBUG : empty space: Size and modification time the same (differ by 0s, within tolerance 1ms) 2025/04/30 16:57:16 DEBUG : empty space: Unchanged skipping 2025/04/30 16:57:16 DEBUG : potato3: Sizes differ (src 68 vs dst 60) 2025/04/30 16:57:16 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-motasih5cadi': Waiting for checks to finish 2025/04/30 16:57:16 INFO : empty space: Deleted 2025/04/30 16:57:16 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-motasih5cadi': Waiting for transfers to finish 2025/04/30 16:57:16 INFO : potato3: Deleted 2025/04/30 16:57:16 INFO : potato2: Moved (server-side) 2025/04/30 16:57:17 INFO : potato3: Moved (server-side) 2025/04/30 16:57:17 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-vufajip5dili" 2025/04/30 16:57:17 DEBUG : Creating backend with remote "TestDrive:crypt/nk82ub02nfka4pfm44095hd49dgkb0a6hf66kf2e8th7jufeijgg" 2025/04/30 16:57:18 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vufajip5dili': Using server-side directory move 2025/04/30 16:57:19 INFO : Encrypted drive 'TestCryptDrive:rclone-test-vufajip5dili': Server side directory move succeeded 2025/04/30 16:57:20 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vufajip5dili': Purge remote 2025/04/30 16:57:20 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-motasih5cadi': Purge remote 2025/04/30 16:57:21 NOTICE: purge failed: directory not found --- PASS: TestServerSideMove (15.67s) === RUN TestServerSideMoveWithFilter run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-yovulez1buxa'", Local "Local file system at /tmp/rclone771422369", Modify Window "1ms" 2025/04/30 16:57:21 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-cicudaz3wuyo" 2025/04/30 16:57:21 DEBUG : Creating backend with remote "TestDrive:crypt/dt5gs8ns6391nk91kfot35v2110c8mbj5eqmths5tbm8qr1bu6m0" 2025/04/30 16:57:24 DEBUG : potato2: md5 = b4c56407a95e1dd5bd02942089c328f9 OK 2025/04/30 16:57:25 DEBUG : empty space: md5 = cebaaf68832a60b19d7d0ab0247e79e1 OK 2025/04/30 16:57:27 DEBUG : potato3: md5 = 598141b4e1d50f5600a1403c05883fc0 OK sync_test.go:1705: Server side move (if possible) Encrypted drive 'TestCryptDrive:rclone-test-yovulez1buxa' -> Encrypted drive 'TestCryptDrive:rclone-test-cicudaz3wuyo' 2025/04/30 16:57:30 DEBUG : empty space: md5 = bb6f0d7e8c3b5eaba5b2c739a4e6c0f9 OK 2025/04/30 16:57:31 DEBUG : potato3: md5 = 21f74e0e89795e40ce533a2f1157cf3d OK 2025/04/30 16:57:32 DEBUG : empty space: Excluded (Size Filter) 2025/04/30 16:57:32 DEBUG : empty space: Excluded 2025/04/30 16:57:32 DEBUG : empty space: Excluded (Size Filter) 2025/04/30 16:57:32 DEBUG : empty space: Excluded 2025/04/30 16:57:32 DEBUG : potato2: Need to transfer - File not found at Destination 2025/04/30 16:57:32 DEBUG : potato3: Sizes differ (src 68 vs dst 60) 2025/04/30 16:57:32 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-cicudaz3wuyo': Waiting for checks to finish 2025/04/30 16:57:32 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-cicudaz3wuyo': Waiting for transfers to finish 2025/04/30 16:57:32 INFO : potato3: Deleted 2025/04/30 16:57:33 INFO : potato2: Moved (server-side) 2025/04/30 16:57:33 INFO : potato3: Moved (server-side) 2025/04/30 16:57:34 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-kuyocah9joki" 2025/04/30 16:57:34 DEBUG : Creating backend with remote "TestDrive:crypt/a6gdtok9aikl3s9vj5mfaeu33vt4s91n98a3vn1t1uhfctt1nb60" 2025/04/30 16:57:35 DEBUG : empty space: Excluded (Size Filter) 2025/04/30 16:57:35 DEBUG : empty space: Excluded 2025/04/30 16:57:35 DEBUG : potato2: Need to transfer - File not found at Destination 2025/04/30 16:57:35 DEBUG : potato3: Need to transfer - File not found at Destination 2025/04/30 16:57:35 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-kuyocah9joki': Waiting for checks to finish 2025/04/30 16:57:35 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-kuyocah9joki': Waiting for transfers to finish 2025/04/30 16:57:36 INFO : potato2: Moved (server-side) 2025/04/30 16:57:37 INFO : potato3: Moved (server-side) 2025/04/30 16:57:37 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-kuyocah9joki': Purge remote 2025/04/30 16:57:38 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-cicudaz3wuyo': Purge remote --- PASS: TestServerSideMoveWithFilter (17.80s) === RUN TestServerSideMoveDeleteEmptySourceDirs run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-yovulez1buxa'", Local "Local file system at /tmp/rclone771422369", Modify Window "1ms" 2025/04/30 16:57:39 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-dabulus0gebe" 2025/04/30 16:57:39 DEBUG : Creating backend with remote "TestDrive:crypt/iv63mvpkt0rprlv7or3togfmoc449hs06gdjnm1r591ro9kgk3hg" 2025/04/30 16:57:42 DEBUG : potato2: md5 = 5ed3f53039ad8fe9ff78e27849a60c0a OK 2025/04/30 16:57:43 DEBUG : empty space: md5 = 97d136a5897b01a86bb2c0994da1c153 OK 2025/04/30 16:57:45 DEBUG : potato3: md5 = 2705c072a645b46119468396d74f2ae0 OK 2025/04/30 16:57:45 INFO : tomatoDir: Making directory sync_test.go:1705: Server side move (if possible) Encrypted drive 'TestCryptDrive:rclone-test-yovulez1buxa' -> Encrypted drive 'TestCryptDrive:rclone-test-dabulus0gebe' 2025/04/30 16:57:48 DEBUG : empty space: md5 = 710c38ebc62d4461be7ec8a3eb1fd475 OK 2025/04/30 16:57:50 DEBUG : potato3: md5 = b37d6915033668f1fd752ea863e254fc OK 2025/04/30 16:57:50 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dabulus0gebe': Using server-side directory move 2025/04/30 16:57:50 INFO : Encrypted drive 'TestCryptDrive:rclone-test-dabulus0gebe': Server side directory move failed - fallback to file moves: can't copy directory - destination already exists 2025/04/30 16:57:50 DEBUG : potato2: Need to transfer - File not found at Destination 2025/04/30 16:57:50 DEBUG : Added delayed dir = "tomatoDir", newDst= 2025/04/30 16:57:50 DEBUG : empty space: Size and modification time the same (differ by 0s, within tolerance 1ms) 2025/04/30 16:57:50 DEBUG : empty space: Unchanged skipping 2025/04/30 16:57:50 DEBUG : potato3: Sizes differ (src 68 vs dst 60) 2025/04/30 16:57:51 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dabulus0gebe': Waiting for checks to finish 2025/04/30 16:57:51 INFO : empty space: Deleted 2025/04/30 16:57:51 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dabulus0gebe': Waiting for transfers to finish 2025/04/30 16:57:51 INFO : potato3: Deleted 2025/04/30 16:57:51 INFO : potato2: Moved (server-side) 2025/04/30 16:57:52 INFO : potato3: Moved (server-side) 2025/04/30 16:57:52 INFO : tomatoDir: Removing directory 2025/04/30 16:57:52 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yovulez1buxa': deleted 1 directories 2025/04/30 16:57:53 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-wuhohuk2roco" 2025/04/30 16:57:53 DEBUG : Creating backend with remote "TestDrive:crypt/qqbpm75141tondgmj4tr0ii5j6b5uq87baco13l8ikvmn595lteg" 2025/04/30 16:57:54 INFO : tomatoDir: Making directory 2025/04/30 16:57:55 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wuhohuk2roco': Using server-side directory move 2025/04/30 16:57:56 INFO : Encrypted drive 'TestCryptDrive:rclone-test-wuhohuk2roco': Server side directory move succeeded 2025/04/30 16:57:57 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wuhohuk2roco': Purge remote 2025/04/30 16:57:58 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dabulus0gebe': Purge remote 2025/04/30 16:57:58 NOTICE: purge failed: directory not found --- PASS: TestServerSideMoveDeleteEmptySourceDirs (19.48s) === RUN TestServerSideMoveOverlap run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-yovulez1buxa'", Local "Local file system at /tmp/rclone771422369", Modify Window "1ms" sync_test.go:1910: Skipping test as remote supports DirMove --- SKIP: TestServerSideMoveOverlap (0.44s) === RUN TestSyncOverlap run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-yovulez1buxa'", Local "Local file system at /tmp/rclone771422369", Modify Window "1ms" 2025/04/30 16:57:59 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-yovulez1buxa/rclone-sync-test" 2025/04/30 16:57:59 DEBUG : Creating backend with remote "TestDrive:crypt/oq8dicu11g0pc2ds2lnqag1s0umk12gt21o3j0hsptghrj7dl370/i7355aa0sb89uagn75vfjqr6s3e3e1h2et8in57abn1fe8qfego0" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-yovulez1buxa'", Local "Local file system at /tmp/rclone771422369", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-yovulez1buxa'", Local "Local file system at /tmp/rclone771422369", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-yovulez1buxa'", Local "Local file system at /tmp/rclone771422369", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-yovulez1buxa'", Local "Local file system at /tmp/rclone771422369", Modify Window "1ms" --- PASS: TestSyncOverlap (3.77s) === RUN TestSyncOverlapWithFilter run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-yovulez1buxa'", Local "Local file system at /tmp/rclone771422369", Modify Window "1ms" 2025/04/30 16:58:03 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-yovulez1buxa/rclone-sync-test" 2025/04/30 16:58:03 DEBUG : Creating backend with remote "TestDrive:crypt/oq8dicu11g0pc2ds2lnqag1s0umk12gt21o3j0hsptghrj7dl370/i7355aa0sb89uagn75vfjqr6s3e3e1h2et8in57abn1fe8qfego0" 2025/04/30 16:58:05 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-yovulez1buxa/rclone-sync-test-include/layer2" 2025/04/30 16:58:05 DEBUG : Creating backend with remote "TestDrive:crypt/oq8dicu11g0pc2ds2lnqag1s0umk12gt21o3j0hsptghrj7dl370/khf2vlblvnbf9ftevqm0htmss73hj1j5a7q328e4ohrgs7e2loe0/n01jpl9202nn9ec1rb75h0f1c4" 2025/04/30 16:58:08 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-yovulez1buxa/rclone-sync-test-ignore-file" 2025/04/30 16:58:08 DEBUG : Creating backend with remote "TestDrive:crypt/oq8dicu11g0pc2ds2lnqag1s0umk12gt21o3j0hsptghrj7dl370/kmf11jujl9uha3tjganvgpkn45bu778hb5vb5riug1c26b38k7sg" 2025/04/30 16:58:12 DEBUG : rclone-sync-test-ignore-file/.ignore: md5 = d4b6eaef69b1b147e9c674038f85a360 OK 2025/04/30 16:58:13 DEBUG : rclone-sync-test-ignore-file: Excluded 2025/04/30 16:58:13 DEBUG : rclone-sync-test: Excluded 2025/04/30 16:58:13 DEBUG : Added delayed dir = "rclone-sync-test-include", newDst= 2025/04/30 16:58:14 DEBUG : rclone-sync-test-include/layer2: Excluded 2025/04/30 16:58:14 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yovulez1buxa/rclone-sync-test': Waiting for checks to finish 2025/04/30 16:58:14 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yovulez1buxa/rclone-sync-test': Waiting for transfers to finish 2025/04/30 16:58:14 DEBUG : Waiting for deletions to finish 2025/04/30 16:58:14 INFO : There was nothing to transfer 2025/04/30 16:58:15 DEBUG : rclone-sync-test-ignore-file: Excluded 2025/04/30 16:58:15 DEBUG : rclone-sync-test: Excluded 2025/04/30 16:58:15 DEBUG : rclone-sync-test-include/layer2: Excluded 2025/04/30 16:58:15 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yovulez1buxa': Waiting for checks to finish 2025/04/30 16:58:15 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yovulez1buxa': Waiting for transfers to finish 2025/04/30 16:58:15 DEBUG : Waiting for deletions to finish 2025/04/30 16:58:15 INFO : rclone-sync-test-include: Removing directory 2025/04/30 16:58:16 DEBUG : khf2vlblvnbf9ftevqm0htmss73hj1j5a7q328e4ohrgs7e2loe0: Rmdir: contains file: "n01jpl9202nn9ec1rb75h0f1c4" 2025/04/30 16:58:16 DEBUG : rclone-sync-test-include: Failed to Rmdir: directory not empty 2025/04/30 16:58:16 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yovulez1buxa': failed to delete 1 directories 2025/04/30 16:58:16 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-yovulez1buxa'", Local "Local file system at /tmp/rclone771422369", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-yovulez1buxa'", Local "Local file system at /tmp/rclone771422369", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-yovulez1buxa'", Local "Local file system at /tmp/rclone771422369", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-yovulez1buxa'", Local "Local file system at /tmp/rclone771422369", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-yovulez1buxa'", Local "Local file system at /tmp/rclone771422369", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-yovulez1buxa'", Local "Local file system at /tmp/rclone771422369", Modify Window "1ms" 2025/04/30 16:58:17 DEBUG : rclone-sync-test-ignore-file: Excluded 2025/04/30 16:58:17 DEBUG : rclone-sync-test: Excluded 2025/04/30 16:58:17 DEBUG : Added delayed dir = "rclone-sync-test-include", newDst= 2025/04/30 16:58:17 DEBUG : rclone-sync-test-include/layer2: Excluded 2025/04/30 16:58:17 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yovulez1buxa/rclone-sync-test-include/layer2': Waiting for checks to finish 2025/04/30 16:58:17 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yovulez1buxa/rclone-sync-test-include/layer2': Waiting for transfers to finish 2025/04/30 16:58:17 DEBUG : Waiting for deletions to finish 2025/04/30 16:58:17 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-yovulez1buxa'", Local "Local file system at /tmp/rclone771422369", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-yovulez1buxa'", Local "Local file system at /tmp/rclone771422369", Modify Window "1ms" 2025/04/30 16:58:18 DEBUG : rclone-sync-test-ignore-file: Excluded 2025/04/30 16:58:19 DEBUG : rclone-sync-test: Excluded 2025/04/30 16:58:19 DEBUG : rclone-sync-test-include/layer2: Excluded 2025/04/30 16:58:19 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yovulez1buxa': Waiting for checks to finish 2025/04/30 16:58:19 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yovulez1buxa': Waiting for transfers to finish 2025/04/30 16:58:19 DEBUG : Waiting for deletions to finish 2025/04/30 16:58:19 INFO : rclone-sync-test-include: Removing directory 2025/04/30 16:58:20 DEBUG : khf2vlblvnbf9ftevqm0htmss73hj1j5a7q328e4ohrgs7e2loe0: Rmdir: contains file: "n01jpl9202nn9ec1rb75h0f1c4" 2025/04/30 16:58:20 DEBUG : rclone-sync-test-include: Failed to Rmdir: directory not empty 2025/04/30 16:58:20 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yovulez1buxa': failed to delete 1 directories 2025/04/30 16:58:20 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-yovulez1buxa'", Local "Local file system at /tmp/rclone771422369", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-yovulez1buxa'", Local "Local file system at /tmp/rclone771422369", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-yovulez1buxa'", Local "Local file system at /tmp/rclone771422369", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-yovulez1buxa'", Local "Local file system at /tmp/rclone771422369", Modify Window "1ms" 2025/04/30 16:58:20 DEBUG : : Excluded 2025/04/30 16:58:20 DEBUG : rclone-sync-test-ignore-file: Excluded 2025/04/30 16:58:21 DEBUG : rclone-sync-test: Excluded 2025/04/30 16:58:21 DEBUG : Added delayed dir = "rclone-sync-test-include", newDst= 2025/04/30 16:58:21 DEBUG : rclone-sync-test-include/layer2: Excluded 2025/04/30 16:58:21 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yovulez1buxa/rclone-sync-test-ignore-file': Waiting for checks to finish 2025/04/30 16:58:21 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yovulez1buxa/rclone-sync-test-ignore-file': Waiting for transfers to finish 2025/04/30 16:58:21 DEBUG : Waiting for deletions to finish 2025/04/30 16:58:21 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-yovulez1buxa'", Local "Local file system at /tmp/rclone771422369", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-yovulez1buxa'", Local "Local file system at /tmp/rclone771422369", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-yovulez1buxa'", Local "Local file system at /tmp/rclone771422369", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-yovulez1buxa'", Local "Local file system at /tmp/rclone771422369", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-yovulez1buxa'", Local "Local file system at /tmp/rclone771422369", Modify Window "1ms" 2025/04/30 16:58:23 DEBUG : khf2vlblvnbf9ftevqm0htmss73hj1j5a7q328e4ohrgs7e2loe0: Rmdir: contains trashed file: "n01jpl9202nn9ec1rb75h0f1c4" 2025/04/30 16:58:24 DEBUG : kmf11jujl9uha3tjganvgpkn45bu778hb5vb5riug1c26b38k7sg: Rmdir: contains trashed file: "i0t74httmdlljg425j6tg570d8" --- PASS: TestSyncOverlapWithFilter (30.45s) === RUN TestSyncCompareDest run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-yovulez1buxa'", Local "Local file system at /tmp/rclone771422369", Modify Window "1ms" 2025/04/30 16:58:33 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-yovulez1buxa/dst" 2025/04/30 16:58:33 DEBUG : Creating backend with remote "TestDrive:crypt/oq8dicu11g0pc2ds2lnqag1s0umk12gt21o3j0hsptghrj7dl370/31u3jie661vd5p8j7rtc3hgbh0" 2025/04/30 16:58:35 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-yovulez1buxa/CompareDest" 2025/04/30 16:58:35 DEBUG : Creating backend with remote "TestDrive:crypt/oq8dicu11g0pc2ds2lnqag1s0umk12gt21o3j0hsptghrj7dl370/gveqi14airsml4bgu7krj116o8" 2025/04/30 16:58:37 DEBUG : one: Need to transfer - File not found at Destination 2025/04/30 16:58:37 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yovulez1buxa/dst': Waiting for checks to finish 2025/04/30 16:58:37 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yovulez1buxa/dst': Waiting for transfers to finish 2025/04/30 16:58:39 DEBUG : one: md5 = e3ac8e79913bc0ca2f60ffe4b0ef2d0c OK 2025/04/30 16:58:39 INFO : one: Copied (new) 2025/04/30 16:58:39 DEBUG : Waiting for deletions to finish 2025/04/30 16:58:40 DEBUG : one: Sizes differ (src 5 vs dst 3) 2025/04/30 16:58:40 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yovulez1buxa/dst': Waiting for checks to finish 2025/04/30 16:58:40 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yovulez1buxa/dst': Waiting for transfers to finish 2025/04/30 16:58:42 DEBUG : one: md5 = 9ac9145e6dfd9cbce60edd94c51f9226 OK 2025/04/30 16:58:42 INFO : one: Copied (replaced existing) 2025/04/30 16:58:42 DEBUG : Waiting for deletions to finish 2025/04/30 16:58:44 DEBUG : dst/one: md5 = 3fd37b66f7fb565333a490d7d329e90c OK 2025/04/30 16:58:46 DEBUG : CompareDest/one: md5 = fcb991b5a0ea93ecdc773210175afba3 OK 2025/04/30 16:58:47 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yovulez1buxa/dst': Waiting for checks to finish 2025/04/30 16:58:47 DEBUG : one: Sizes differ (src 5 vs dst 3) 2025/04/30 16:58:47 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/04/30 16:58:47 DEBUG : one: Destination found in --compare-dest, skipping 2025/04/30 16:58:47 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yovulez1buxa/dst': Waiting for transfers to finish 2025/04/30 16:58:47 DEBUG : Waiting for deletions to finish 2025/04/30 16:58:47 INFO : There was nothing to transfer 2025/04/30 16:58:49 DEBUG : CompareDest/two: md5 = 4b10c4ae5c51fdf01fe95ba6affeabe7 OK 2025/04/30 16:58:50 DEBUG : two: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/04/30 16:58:50 DEBUG : two: Destination found in --compare-dest, skipping 2025/04/30 16:58:50 DEBUG : one: Sizes differ (src 5 vs dst 3) 2025/04/30 16:58:50 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yovulez1buxa/dst': Waiting for checks to finish 2025/04/30 16:58:50 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/04/30 16:58:50 DEBUG : one: Destination found in --compare-dest, skipping 2025/04/30 16:58:50 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yovulez1buxa/dst': Waiting for transfers to finish 2025/04/30 16:58:50 DEBUG : Waiting for deletions to finish 2025/04/30 16:58:50 INFO : There was nothing to transfer 2025/04/30 16:58:51 DEBUG : two: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/04/30 16:58:51 DEBUG : two: Destination found in --compare-dest, skipping 2025/04/30 16:58:51 DEBUG : one: Sizes differ (src 5 vs dst 3) 2025/04/30 16:58:51 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yovulez1buxa/dst': Waiting for checks to finish 2025/04/30 16:58:52 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/04/30 16:58:52 DEBUG : one: Destination found in --compare-dest, skipping 2025/04/30 16:58:52 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yovulez1buxa/dst': Waiting for transfers to finish 2025/04/30 16:58:52 DEBUG : Waiting for deletions to finish 2025/04/30 16:58:52 INFO : There was nothing to transfer sync_test.go:2175: No hash on uploaded file so skipping compare timestamp test 2025/04/30 16:58:53 DEBUG : two: Sizes differ (src 5 vs dst 3) 2025/04/30 16:58:53 DEBUG : two: Need to transfer - File not found at Destination 2025/04/30 16:58:53 DEBUG : one: Sizes differ (src 5 vs dst 3) 2025/04/30 16:58:53 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yovulez1buxa/dst': Waiting for checks to finish 2025/04/30 16:58:53 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/04/30 16:58:53 DEBUG : one: Destination found in --compare-dest, skipping 2025/04/30 16:58:53 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yovulez1buxa/dst': Waiting for transfers to finish 2025/04/30 16:58:54 DEBUG : two: md5 = be8642d84bc2a844b47af6865e3b7bb5 OK 2025/04/30 16:58:54 INFO : two: Copied (new) 2025/04/30 16:58:54 DEBUG : Waiting for deletions to finish 2025/04/30 16:58:58 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k" 2025/04/30 16:58:58 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" 2025/04/30 16:58:59 DEBUG : gveqi14airsml4bgu7krj116o8: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k" 2025/04/30 16:58:59 DEBUG : gveqi14airsml4bgu7krj116o8: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" --- PASS: TestSyncCompareDest (26.05s) === RUN TestSyncMultipleCompareDest run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-yovulez1buxa'", Local "Local file system at /tmp/rclone771422369", Modify Window "1ms" 2025/04/30 16:59:01 DEBUG : pre-dest1/1: md5 = 2c94fd41fe782ed1d1d6b5d144416192 OK 2025/04/30 16:59:04 DEBUG : pre-dest2/2: md5 = d66b9adc21dfbd575a327d04062cce0e OK 2025/04/30 16:59:04 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-yovulez1buxa/dest" 2025/04/30 16:59:04 DEBUG : Creating backend with remote "TestDrive:crypt/oq8dicu11g0pc2ds2lnqag1s0umk12gt21o3j0hsptghrj7dl370/rg03c1jvnehrrc617i0lnqjddc" 2025/04/30 16:59:06 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-yovulez1buxa/pre-dest1" 2025/04/30 16:59:06 DEBUG : Creating backend with remote "TestDrive:crypt/oq8dicu11g0pc2ds2lnqag1s0umk12gt21o3j0hsptghrj7dl370/bbnblvh6k061ssopqrp18kd7gc" 2025/04/30 16:59:06 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-yovulez1buxa/pre-dest2" 2025/04/30 16:59:07 DEBUG : Creating backend with remote "TestDrive:crypt/oq8dicu11g0pc2ds2lnqag1s0umk12gt21o3j0hsptghrj7dl370/dgicm1h6b5ejvlltm8eeif0bnk" 2025/04/30 16:59:08 DEBUG : 1: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/30 16:59:08 DEBUG : 1: Destination found in --compare-dest, skipping 2025/04/30 16:59:08 DEBUG : 2: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/30 16:59:08 DEBUG : 2: Destination found in --compare-dest, skipping 2025/04/30 16:59:09 DEBUG : 3: Need to transfer - File not found at Destination 2025/04/30 16:59:09 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yovulez1buxa/dest': Waiting for checks to finish 2025/04/30 16:59:09 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yovulez1buxa/dest': Waiting for transfers to finish 2025/04/30 16:59:11 DEBUG : 3: md5 = 170b8c97458128038aab6f6154ec09cc OK 2025/04/30 16:59:11 INFO : 3: Copied (new) 2025/04/30 16:59:11 DEBUG : Waiting for deletions to finish 2025/04/30 16:59:14 DEBUG : dgicm1h6b5ejvlltm8eeif0bnk: Rmdir: contains trashed file: "1ghu8geql9vrl726n32nrf65bc" 2025/04/30 16:59:15 DEBUG : bbnblvh6k061ssopqrp18kd7gc: Rmdir: contains trashed file: "skbfko3oil7es0lj68ob574sro" 2025/04/30 16:59:15 DEBUG : rg03c1jvnehrrc617i0lnqjddc: Rmdir: contains trashed file: "g072p7hmjchlnj0gibe64c1epg" --- PASS: TestSyncMultipleCompareDest (16.80s) === RUN TestSyncCopyDest run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-yovulez1buxa'", Local "Local file system at /tmp/rclone771422369", Modify Window "1ms" 2025/04/30 16:59:16 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-yovulez1buxa/dst" 2025/04/30 16:59:16 DEBUG : Creating backend with remote "TestDrive:crypt/oq8dicu11g0pc2ds2lnqag1s0umk12gt21o3j0hsptghrj7dl370/31u3jie661vd5p8j7rtc3hgbh0" 2025/04/30 16:59:18 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-yovulez1buxa/CopyDest" 2025/04/30 16:59:18 DEBUG : Creating backend with remote "TestDrive:crypt/oq8dicu11g0pc2ds2lnqag1s0umk12gt21o3j0hsptghrj7dl370/d09o6po3f7bm6ce32vdgs8h9ls" 2025/04/30 16:59:19 DEBUG : one: Need to transfer - File not found at Destination 2025/04/30 16:59:19 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yovulez1buxa/dst': Waiting for checks to finish 2025/04/30 16:59:19 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yovulez1buxa/dst': Waiting for transfers to finish 2025/04/30 16:59:22 DEBUG : one: md5 = ade9bd8e99071470aaed1c681d6686b7 OK 2025/04/30 16:59:22 INFO : one: Copied (new) 2025/04/30 16:59:22 DEBUG : Waiting for deletions to finish 2025/04/30 16:59:23 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yovulez1buxa/dst': Waiting for checks to finish 2025/04/30 16:59:23 DEBUG : one: Sizes differ (src 5 vs dst 3) 2025/04/30 16:59:23 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yovulez1buxa/dst': Waiting for transfers to finish 2025/04/30 16:59:24 DEBUG : one: md5 = e4fe8c3a94fe829ab02d751ad3457ba3 OK 2025/04/30 16:59:24 INFO : one: Copied (replaced existing) 2025/04/30 16:59:24 DEBUG : Waiting for deletions to finish 2025/04/30 16:59:26 DEBUG : dst/one: md5 = 4daacd7a3c6cefc0876fc32cac0e9f37 OK 2025/04/30 16:59:29 DEBUG : CopyDest/one: md5 = 07ef847b9e1dad5382b9faa87bb36187 OK 2025/04/30 16:59:29 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-yovulez1buxa/BackupDir" 2025/04/30 16:59:29 DEBUG : Creating backend with remote "TestDrive:crypt/oq8dicu11g0pc2ds2lnqag1s0umk12gt21o3j0hsptghrj7dl370/s6dbk3lfi7c9kfvo6j7bla9m0g" 2025/04/30 16:59:31 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yovulez1buxa/dst': Waiting for checks to finish 2025/04/30 16:59:31 DEBUG : one: Sizes differ (src 5 vs dst 3) 2025/04/30 16:59:31 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/04/30 16:59:31 DEBUG : one: Sizes differ (src 5 vs dst 3) 2025/04/30 16:59:33 INFO : one: Moved (server-side) 2025/04/30 16:59:34 INFO : one: Copied (server-side copy) 2025/04/30 16:59:34 DEBUG : one: Destination found in --copy-dest, using server-side copy 2025/04/30 16:59:34 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yovulez1buxa/dst': Waiting for transfers to finish 2025/04/30 16:59:34 DEBUG : Waiting for deletions to finish 2025/04/30 16:59:36 DEBUG : CopyDest/two: md5 = 9f5bbcf1f100cd182679079960eaa0d7 OK 2025/04/30 16:59:37 DEBUG : two: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/04/30 16:59:38 INFO : two: Copied (server-side copy) 2025/04/30 16:59:38 DEBUG : two: Destination found in --copy-dest, using server-side copy 2025/04/30 16:59:38 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/04/30 16:59:38 DEBUG : one: Unchanged skipping 2025/04/30 16:59:38 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yovulez1buxa/dst': Waiting for checks to finish 2025/04/30 16:59:38 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yovulez1buxa/dst': Waiting for transfers to finish 2025/04/30 16:59:38 DEBUG : Waiting for deletions to finish 2025/04/30 16:59:39 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/04/30 16:59:39 DEBUG : one: Unchanged skipping 2025/04/30 16:59:39 DEBUG : two: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/04/30 16:59:39 DEBUG : two: Unchanged skipping 2025/04/30 16:59:39 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yovulez1buxa/dst': Waiting for checks to finish 2025/04/30 16:59:39 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yovulez1buxa/dst': Waiting for transfers to finish 2025/04/30 16:59:39 DEBUG : Waiting for deletions to finish 2025/04/30 16:59:39 INFO : There was nothing to transfer 2025/04/30 16:59:41 DEBUG : CopyDest/three: md5 = 810571546abe5023a4dfcee4d1ed5626 OK 2025/04/30 16:59:42 DEBUG : three: Sizes differ (src 7 vs dst 5) 2025/04/30 16:59:42 DEBUG : three: Destination not found in --copy-dest 2025/04/30 16:59:42 DEBUG : three: Need to transfer - File not found at Destination 2025/04/30 16:59:42 DEBUG : two: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/04/30 16:59:42 DEBUG : two: Unchanged skipping 2025/04/30 16:59:42 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/04/30 16:59:42 DEBUG : one: Unchanged skipping 2025/04/30 16:59:42 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yovulez1buxa/dst': Waiting for checks to finish 2025/04/30 16:59:42 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yovulez1buxa/dst': Waiting for transfers to finish 2025/04/30 16:59:44 DEBUG : three: md5 = 7ebddd88b2676a3d65cf8fea9ccedb0d OK 2025/04/30 16:59:44 INFO : three: Copied (new) 2025/04/30 16:59:44 DEBUG : Waiting for deletions to finish 2025/04/30 16:59:48 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "b6jdmn2b1adrhc8vikh7edr9os" 2025/04/30 16:59:48 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" 2025/04/30 16:59:48 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k" 2025/04/30 16:59:49 DEBUG : d09o6po3f7bm6ce32vdgs8h9ls: Rmdir: contains trashed file: "b6jdmn2b1adrhc8vikh7edr9os" 2025/04/30 16:59:49 DEBUG : d09o6po3f7bm6ce32vdgs8h9ls: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" 2025/04/30 16:59:49 DEBUG : d09o6po3f7bm6ce32vdgs8h9ls: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k" 2025/04/30 16:59:49 DEBUG : s6dbk3lfi7c9kfvo6j7bla9m0g: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" --- PASS: TestSyncCopyDest (34.13s) === RUN TestSyncBackupDir run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-yovulez1buxa'", Local "Local file system at /tmp/rclone771422369", Modify Window "1ms" 2025/04/30 16:59:52 DEBUG : dst/one: md5 = ca06ea0bbd0ede1bcc8c59f4efc36d7b OK 2025/04/30 16:59:54 DEBUG : dst/two: md5 = bcaa27334e96a1281daaf445fe4ac516 OK 2025/04/30 16:59:55 DEBUG : dst/three.txt: md5 = a8585acd489c045c5265f8a7e90e89fe OK 2025/04/30 16:59:56 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-yovulez1buxa/dst" 2025/04/30 16:59:56 DEBUG : Creating backend with remote "TestDrive:crypt/oq8dicu11g0pc2ds2lnqag1s0umk12gt21o3j0hsptghrj7dl370/31u3jie661vd5p8j7rtc3hgbh0" 2025/04/30 16:59:57 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-yovulez1buxa/backup" 2025/04/30 16:59:57 DEBUG : Creating backend with remote "TestDrive:crypt/oq8dicu11g0pc2ds2lnqag1s0umk12gt21o3j0hsptghrj7dl370/1nrff024r7pq65ecp72fc28jb0" 2025/04/30 16:59:58 DEBUG : one: Sizes differ (src 4 vs dst 3) 2025/04/30 16:59:58 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/30 16:59:58 DEBUG : two: Unchanged skipping 2025/04/30 16:59:58 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yovulez1buxa/dst': Waiting for checks to finish 2025/04/30 17:00:00 INFO : one: Moved (server-side) 2025/04/30 17:00:00 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yovulez1buxa/dst': Waiting for transfers to finish 2025/04/30 17:00:01 DEBUG : one: md5 = a67b77eb78f9e6964059284a3b681c09 OK 2025/04/30 17:00:01 INFO : one: Copied (new) 2025/04/30 17:00:01 DEBUG : Waiting for deletions to finish 2025/04/30 17:00:02 INFO : three.txt: Moved (server-side) 2025/04/30 17:00:02 INFO : three.txt: Moved into backup dir 2025/04/30 17:00:05 DEBUG : dst/three.txt: md5 = 5e4b565ad5b20b4054ec296797ca07a8 OK 2025/04/30 17:00:05 DEBUG : one: Sizes differ (src 5 vs dst 4) 2025/04/30 17:00:05 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/30 17:00:05 DEBUG : two: Unchanged skipping 2025/04/30 17:00:05 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yovulez1buxa/dst': Waiting for checks to finish 2025/04/30 17:00:06 INFO : one: Deleted 2025/04/30 17:00:07 INFO : one: Moved (server-side) 2025/04/30 17:00:07 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yovulez1buxa/dst': Waiting for transfers to finish 2025/04/30 17:00:09 DEBUG : one: md5 = 079e1ba72d4ef441a80a145f75b949b9 OK 2025/04/30 17:00:09 INFO : one: Copied (new) 2025/04/30 17:00:09 DEBUG : Waiting for deletions to finish 2025/04/30 17:00:09 INFO : three.txt: Deleted 2025/04/30 17:00:10 INFO : three.txt: Moved (server-side) 2025/04/30 17:00:10 INFO : three.txt: Moved into backup dir 2025/04/30 17:00:13 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" 2025/04/30 17:00:13 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k" 2025/04/30 17:00:14 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "tr2hj63d80ftlmvm6a952snjcc" 2025/04/30 17:00:14 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" 2025/04/30 17:00:14 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "tr2hj63d80ftlmvm6a952snjcc" 2025/04/30 17:00:14 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" --- PASS: TestSyncBackupDir (24.27s) === RUN TestSyncBackupDirWithSuffix run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-yovulez1buxa'", Local "Local file system at /tmp/rclone771422369", Modify Window "1ms" 2025/04/30 17:00:17 DEBUG : dst/one: md5 = 571dfb9e009a2f41c2e19b0e6bb0cc67 OK 2025/04/30 17:00:18 DEBUG : dst/two: md5 = 3d6a50e180098168a3738575a7f3a05e OK 2025/04/30 17:00:20 DEBUG : dst/three.txt: md5 = e9adb878101103558dcd863f2edc416a OK 2025/04/30 17:00:20 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-yovulez1buxa/dst" 2025/04/30 17:00:20 DEBUG : Creating backend with remote "TestDrive:crypt/oq8dicu11g0pc2ds2lnqag1s0umk12gt21o3j0hsptghrj7dl370/31u3jie661vd5p8j7rtc3hgbh0" 2025/04/30 17:00:21 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-yovulez1buxa/backup" 2025/04/30 17:00:21 DEBUG : Creating backend with remote "TestDrive:crypt/oq8dicu11g0pc2ds2lnqag1s0umk12gt21o3j0hsptghrj7dl370/1nrff024r7pq65ecp72fc28jb0" 2025/04/30 17:00:23 DEBUG : one: Sizes differ (src 4 vs dst 3) 2025/04/30 17:00:23 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yovulez1buxa/dst': Waiting for checks to finish 2025/04/30 17:00:23 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/30 17:00:23 DEBUG : two: Unchanged skipping 2025/04/30 17:00:25 INFO : one: Moved (server-side) to: one.bak 2025/04/30 17:00:25 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yovulez1buxa/dst': Waiting for transfers to finish 2025/04/30 17:00:26 DEBUG : one: md5 = 8f2648b0d4190f96752d4eb238f13a65 OK 2025/04/30 17:00:26 INFO : one: Copied (new) 2025/04/30 17:00:26 DEBUG : Waiting for deletions to finish 2025/04/30 17:00:27 INFO : three.txt: Moved (server-side) to: three.txt.bak 2025/04/30 17:00:27 INFO : three.txt: Moved into backup dir 2025/04/30 17:00:29 DEBUG : dst/three.txt: md5 = e13a869218036334119a4ea8f1175729 OK 2025/04/30 17:00:30 DEBUG : one: Sizes differ (src 5 vs dst 4) 2025/04/30 17:00:30 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yovulez1buxa/dst': Waiting for checks to finish 2025/04/30 17:00:30 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/30 17:00:30 DEBUG : two: Unchanged skipping 2025/04/30 17:00:30 INFO : one.bak: Deleted 2025/04/30 17:00:31 INFO : one: Moved (server-side) to: one.bak 2025/04/30 17:00:31 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yovulez1buxa/dst': Waiting for transfers to finish 2025/04/30 17:00:32 DEBUG : one: md5 = 14fb37afaf202972a91edb2312c11667 OK 2025/04/30 17:00:32 INFO : one: Copied (new) 2025/04/30 17:00:32 DEBUG : Waiting for deletions to finish 2025/04/30 17:00:33 INFO : three.txt.bak: Deleted 2025/04/30 17:00:34 INFO : three.txt: Moved (server-side) to: three.txt.bak 2025/04/30 17:00:34 INFO : three.txt: Moved into backup dir 2025/04/30 17:00:37 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" 2025/04/30 17:00:37 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k" 2025/04/30 17:00:38 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "sk91qgsqfn0r271r2ehsaoc20c" 2025/04/30 17:00:38 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "qltcak2uaegtmcoa8vijdppbp8" 2025/04/30 17:00:38 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "qltcak2uaegtmcoa8vijdppbp8" 2025/04/30 17:00:38 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "sk91qgsqfn0r271r2ehsaoc20c" --- PASS: TestSyncBackupDirWithSuffix (24.32s) === RUN TestSyncBackupDirWithSuffixKeepExtension run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-yovulez1buxa'", Local "Local file system at /tmp/rclone771422369", Modify Window "1ms" 2025/04/30 17:00:41 DEBUG : dst/one: md5 = 260c526aae3e73f92f8d913bbfc87373 OK 2025/04/30 17:00:43 DEBUG : dst/two: md5 = df18f851882a8fae0f1f9f08e852a800 OK 2025/04/30 17:00:44 DEBUG : dst/three.txt: md5 = 6b6ea0936055f5b00a0dd130b0ea2bee OK 2025/04/30 17:00:45 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-yovulez1buxa/dst" 2025/04/30 17:00:45 DEBUG : Config file has changed externally - reloading 2025/04/30 17:00:45 DEBUG : Creating backend with remote "TestDrive:crypt/oq8dicu11g0pc2ds2lnqag1s0umk12gt21o3j0hsptghrj7dl370/31u3jie661vd5p8j7rtc3hgbh0" 2025/04/30 17:00:45 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-yovulez1buxa/backup" 2025/04/30 17:00:46 DEBUG : Creating backend with remote "TestDrive:crypt/oq8dicu11g0pc2ds2lnqag1s0umk12gt21o3j0hsptghrj7dl370/1nrff024r7pq65ecp72fc28jb0" 2025/04/30 17:00:47 DEBUG : one: Sizes differ (src 4 vs dst 3) 2025/04/30 17:00:47 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/30 17:00:47 DEBUG : two: Unchanged skipping 2025/04/30 17:00:47 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yovulez1buxa/dst': Waiting for checks to finish 2025/04/30 17:00:49 INFO : one: Moved (server-side) to: one-2019-01-01 2025/04/30 17:00:49 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yovulez1buxa/dst': Waiting for transfers to finish 2025/04/30 17:00:51 DEBUG : one: md5 = 209ed9c4089659c7d77b11eef5244044 OK 2025/04/30 17:00:51 INFO : one: Copied (new) 2025/04/30 17:00:51 DEBUG : Waiting for deletions to finish 2025/04/30 17:00:51 INFO : three.txt: Moved (server-side) to: three-2019-01-01.txt 2025/04/30 17:00:51 INFO : three.txt: Moved into backup dir 2025/04/30 17:00:53 DEBUG : dst/three.txt: md5 = d55fd2ca025ad6a3437b7ca8fe1fde45 OK 2025/04/30 17:00:54 DEBUG : one: Sizes differ (src 5 vs dst 4) 2025/04/30 17:00:54 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/30 17:00:54 DEBUG : two: Unchanged skipping 2025/04/30 17:00:54 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yovulez1buxa/dst': Waiting for checks to finish 2025/04/30 17:00:55 INFO : one-2019-01-01: Deleted 2025/04/30 17:00:56 INFO : one: Moved (server-side) to: one-2019-01-01 2025/04/30 17:00:56 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yovulez1buxa/dst': Waiting for transfers to finish 2025/04/30 17:00:57 DEBUG : one: md5 = 53256cb60fe86bd1d6dbb48b2354c8e2 OK 2025/04/30 17:00:57 INFO : one: Copied (new) 2025/04/30 17:00:57 DEBUG : Waiting for deletions to finish 2025/04/30 17:00:58 INFO : three-2019-01-01.txt: Deleted 2025/04/30 17:00:59 INFO : three.txt: Moved (server-side) to: three-2019-01-01.txt 2025/04/30 17:00:59 INFO : three.txt: Moved into backup dir 2025/04/30 17:01:02 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" 2025/04/30 17:01:02 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k" 2025/04/30 17:01:03 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "jcjl1bv3ep0v8kt35lqql1co90" 2025/04/30 17:01:03 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "qtq2f6qq4lgpsmj88vb7147qje3prudmtfdtr2342fth58vo9a50" 2025/04/30 17:01:03 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "jcjl1bv3ep0v8kt35lqql1co90" 2025/04/30 17:01:03 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "qtq2f6qq4lgpsmj88vb7147qje3prudmtfdtr2342fth58vo9a50" --- PASS: TestSyncBackupDirWithSuffixKeepExtension (24.69s) === RUN TestSyncBackupDirSuffixOnly run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-yovulez1buxa'", Local "Local file system at /tmp/rclone771422369", Modify Window "1ms" 2025/04/30 17:01:06 DEBUG : dst/one: md5 = bae31c3ba6c32b48e7f2109029ce0de9 OK 2025/04/30 17:01:07 DEBUG : dst/two: md5 = bac5b07ffca085fc98c0a33caec05e5e OK 2025/04/30 17:01:09 DEBUG : dst/three.txt: md5 = 3aa0e7ccfcf30b7f127f626cd346817f OK 2025/04/30 17:01:09 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-yovulez1buxa/dst" 2025/04/30 17:01:09 DEBUG : Creating backend with remote "TestDrive:crypt/oq8dicu11g0pc2ds2lnqag1s0umk12gt21o3j0hsptghrj7dl370/31u3jie661vd5p8j7rtc3hgbh0" 2025/04/30 17:01:10 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/30 17:01:10 DEBUG : two: Unchanged skipping 2025/04/30 17:01:10 DEBUG : one: Sizes differ (src 4 vs dst 3) 2025/04/30 17:01:10 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yovulez1buxa/dst': Waiting for checks to finish 2025/04/30 17:01:11 INFO : one: Moved (server-side) to: one.bak 2025/04/30 17:01:11 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yovulez1buxa/dst': Waiting for transfers to finish 2025/04/30 17:01:13 DEBUG : one: md5 = 1436ac2157c41a0292b02a82fd3e34f0 OK 2025/04/30 17:01:13 INFO : one: Copied (new) 2025/04/30 17:01:13 DEBUG : Waiting for deletions to finish 2025/04/30 17:01:14 INFO : three.txt: Moved (server-side) to: three.txt.bak 2025/04/30 17:01:14 INFO : three.txt: Moved into backup dir 2025/04/30 17:01:15 DEBUG : dst/three.txt: md5 = 1164ccfb3e7eacb9d6aa58e60c68262d OK 2025/04/30 17:01:16 DEBUG : three.txt.bak: Excluded (Path Filter) 2025/04/30 17:01:16 DEBUG : three.txt.bak: Excluded 2025/04/30 17:01:16 DEBUG : one.bak: Excluded (Path Filter) 2025/04/30 17:01:16 DEBUG : one.bak: Excluded 2025/04/30 17:01:16 DEBUG : one: Sizes differ (src 5 vs dst 4) 2025/04/30 17:01:16 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/30 17:01:16 DEBUG : two: Unchanged skipping 2025/04/30 17:01:16 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yovulez1buxa/dst': Waiting for checks to finish 2025/04/30 17:01:17 INFO : one.bak: Deleted 2025/04/30 17:01:18 INFO : one: Moved (server-side) to: one.bak 2025/04/30 17:01:18 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yovulez1buxa/dst': Waiting for transfers to finish 2025/04/30 17:01:19 DEBUG : one: md5 = ae1daceb74cc9d84f71f0acdcf5bcc22 OK 2025/04/30 17:01:19 INFO : one: Copied (new) 2025/04/30 17:01:19 DEBUG : Waiting for deletions to finish 2025/04/30 17:01:20 INFO : three.txt.bak: Deleted 2025/04/30 17:01:20 INFO : three.txt: Moved (server-side) to: three.txt.bak 2025/04/30 17:01:20 INFO : three.txt: Moved into backup dir 2025/04/30 17:01:23 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" 2025/04/30 17:01:23 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "sk91qgsqfn0r271r2ehsaoc20c" 2025/04/30 17:01:23 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "qltcak2uaegtmcoa8vijdppbp8" 2025/04/30 17:01:23 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k" 2025/04/30 17:01:23 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "sk91qgsqfn0r271r2ehsaoc20c" 2025/04/30 17:01:23 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "qltcak2uaegtmcoa8vijdppbp8" --- PASS: TestSyncBackupDirSuffixOnly (20.68s) === RUN TestSyncSuffix run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-yovulez1buxa'", Local "Local file system at /tmp/rclone771422369", Modify Window "1ms" 2025/04/30 17:01:27 DEBUG : dst/one: md5 = cfbb2753ad36fef23ca93b5db8503f88 OK 2025/04/30 17:01:28 DEBUG : dst/two: md5 = 87bf88fbb75984e60d114c7c72162664 OK 2025/04/30 17:01:29 DEBUG : dst/three.txt: md5 = 2a9d7d1ab8637cfcdb1ef9f43ff5cac9 OK 2025/04/30 17:01:30 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-yovulez1buxa/dst" 2025/04/30 17:01:30 DEBUG : Creating backend with remote "TestDrive:crypt/oq8dicu11g0pc2ds2lnqag1s0umk12gt21o3j0hsptghrj7dl370/31u3jie661vd5p8j7rtc3hgbh0" 2025/04/30 17:01:31 DEBUG : one: Sizes differ (src 4 vs dst 3) 2025/04/30 17:01:32 INFO : one: Moved (server-side) to: one.bak 2025/04/30 17:01:33 DEBUG : one: md5 = 2e47b3d329c07866b831d67527345cb0 OK 2025/04/30 17:01:33 INFO : one: Copied (new) 2025/04/30 17:01:33 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/30 17:01:33 DEBUG : two: Unchanged skipping 2025/04/30 17:01:34 DEBUG : three.txt: Sizes differ (src 6 vs dst 5) 2025/04/30 17:01:34 INFO : three.txt: Moved (server-side) to: three.txt.bak 2025/04/30 17:01:36 DEBUG : three.txt: md5 = fe32b0e237057e3f9f1d53e7affa202d OK 2025/04/30 17:01:36 INFO : three.txt: Copied (new) 2025/04/30 17:01:37 DEBUG : one: Sizes differ (src 5 vs dst 4) 2025/04/30 17:01:38 INFO : one.bak: Deleted 2025/04/30 17:01:38 INFO : one: Moved (server-side) to: one.bak 2025/04/30 17:01:40 DEBUG : one: md5 = cf76bd3121a986b601e07a54ec3724d9 OK 2025/04/30 17:01:40 INFO : one: Copied (new) 2025/04/30 17:01:40 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/30 17:01:40 DEBUG : two: Unchanged skipping 2025/04/30 17:01:40 DEBUG : three.txt: Sizes differ (src 19 vs dst 6) 2025/04/30 17:01:41 INFO : three.txt.bak: Deleted 2025/04/30 17:01:42 INFO : three.txt: Moved (server-side) to: three.txt.bak 2025/04/30 17:01:43 DEBUG : three.txt: md5 = 7da37b19138a6b152b9e19b39d286452 OK 2025/04/30 17:01:43 INFO : three.txt: Copied (new) 2025/04/30 17:01:47 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "tr2hj63d80ftlmvm6a952snjcc" 2025/04/30 17:01:47 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" 2025/04/30 17:01:47 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "qltcak2uaegtmcoa8vijdppbp8" 2025/04/30 17:01:47 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "sk91qgsqfn0r271r2ehsaoc20c" 2025/04/30 17:01:47 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "qltcak2uaegtmcoa8vijdppbp8" 2025/04/30 17:01:47 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "sk91qgsqfn0r271r2ehsaoc20c" 2025/04/30 17:01:47 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k" --- PASS: TestSyncSuffix (23.91s) === RUN TestSyncSuffixKeepExtension run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-yovulez1buxa'", Local "Local file system at /tmp/rclone771422369", Modify Window "1ms" 2025/04/30 17:01:50 DEBUG : dst/one: md5 = 5e1ab1a57f789ad49e17c612937a4b76 OK 2025/04/30 17:01:52 DEBUG : dst/two: md5 = 8dc07a654fb2b8325252140c2f92ea5f OK 2025/04/30 17:01:54 DEBUG : dst/three.txt: md5 = 9e9ebd6ac242b6fbd565c7832d2028fe OK 2025/04/30 17:01:54 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-yovulez1buxa/dst" 2025/04/30 17:01:54 DEBUG : Creating backend with remote "TestDrive:crypt/oq8dicu11g0pc2ds2lnqag1s0umk12gt21o3j0hsptghrj7dl370/31u3jie661vd5p8j7rtc3hgbh0" 2025/04/30 17:01:55 DEBUG : one: Sizes differ (src 4 vs dst 3) 2025/04/30 17:01:56 INFO : one: Moved (server-side) to: one-2019-01-01 2025/04/30 17:01:57 DEBUG : one: md5 = 4e62a333aeba028169cf6fb6d56877db OK 2025/04/30 17:01:57 INFO : one: Copied (new) 2025/04/30 17:01:58 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/30 17:01:58 DEBUG : two: Unchanged skipping 2025/04/30 17:01:58 DEBUG : three.txt: Sizes differ (src 6 vs dst 5) 2025/04/30 17:01:59 INFO : three.txt: Moved (server-side) to: three-2019-01-01.txt 2025/04/30 17:02:00 DEBUG : three.txt: md5 = 73b60f31627e05d175ddb303dc2a6867 OK 2025/04/30 17:02:00 INFO : three.txt: Copied (new) 2025/04/30 17:02:02 DEBUG : one: Sizes differ (src 5 vs dst 4) 2025/04/30 17:02:02 INFO : one-2019-01-01: Deleted 2025/04/30 17:02:03 INFO : one: Moved (server-side) to: one-2019-01-01 2025/04/30 17:02:04 DEBUG : one: md5 = 60ea5193267d4a71900103c419f8d599 OK 2025/04/30 17:02:04 INFO : one: Copied (new) 2025/04/30 17:02:05 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/30 17:02:05 DEBUG : two: Unchanged skipping 2025/04/30 17:02:05 DEBUG : three.txt: Sizes differ (src 19 vs dst 6) 2025/04/30 17:02:06 INFO : three-2019-01-01.txt: Deleted 2025/04/30 17:02:06 INFO : three.txt: Moved (server-side) to: three-2019-01-01.txt 2025/04/30 17:02:08 DEBUG : three.txt: md5 = 5b1e5883220068d53bd61bab66218138 OK 2025/04/30 17:02:08 INFO : three.txt: Copied (new) 2025/04/30 17:02:11 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "tr2hj63d80ftlmvm6a952snjcc" 2025/04/30 17:02:11 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" 2025/04/30 17:02:11 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "jcjl1bv3ep0v8kt35lqql1co90" 2025/04/30 17:02:11 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "qtq2f6qq4lgpsmj88vb7147qje3prudmtfdtr2342fth58vo9a50" 2025/04/30 17:02:11 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "jcjl1bv3ep0v8kt35lqql1co90" 2025/04/30 17:02:11 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k" 2025/04/30 17:02:11 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "qtq2f6qq4lgpsmj88vb7147qje3prudmtfdtr2342fth58vo9a50" --- PASS: TestSyncSuffixKeepExtension (24.04s) === RUN TestSyncUTFNorm run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-yovulez1buxa'", Local "Local file system at /tmp/rclone771422369", Modify Window "1ms" 2025/04/30 17:02:14 DEBUG : Testêé: md5 = de3e46003e02130cca5818046006562b OK 2025/04/30 17:02:14 DEBUG : Testêé: Sizes differ (src 14 vs dst 18) 2025/04/30 17:02:14 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yovulez1buxa': Waiting for checks to finish 2025/04/30 17:02:14 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yovulez1buxa': Waiting for transfers to finish 2025/04/30 17:02:15 DEBUG : Testêé: md5 = c4e111b6224b0f4d057ffa95ad995c7e OK 2025/04/30 17:02:15 INFO : Testêé: Copied (replaced existing) to: Testêé 2025/04/30 17:02:15 DEBUG : Waiting for deletions to finish --- PASS: TestSyncUTFNorm (4.52s) === RUN TestSyncImmutable run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-yovulez1buxa'", Local "Local file system at /tmp/rclone771422369", Modify Window "1ms" 2025/04/30 17:02:17 DEBUG : existing: Need to transfer - File not found at Destination 2025/04/30 17:02:17 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yovulez1buxa': Waiting for checks to finish 2025/04/30 17:02:17 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yovulez1buxa': Waiting for transfers to finish 2025/04/30 17:02:19 DEBUG : existing: md5 = 2ba0059303646f15b21fce92a4187676 OK 2025/04/30 17:02:19 INFO : existing: Copied (new) 2025/04/30 17:02:19 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-yovulez1buxa'", Local "Local file system at /tmp/rclone771422369", Modify Window "1ms" 2025/04/30 17:02:19 DEBUG : existing: Sizes differ (src 8 vs dst 6) 2025/04/30 17:02:19 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yovulez1buxa': Waiting for checks to finish 2025/04/30 17:02:19 ERROR : existing: Source and destination exist but do not match: immutable file modified 2025/04/30 17:02:19 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yovulez1buxa': Waiting for transfers to finish 2025/04/30 17:02:19 ERROR : Encrypted drive 'TestCryptDrive:rclone-test-yovulez1buxa': not deleting files as there were IO errors 2025/04/30 17:02:19 ERROR : Encrypted drive 'TestCryptDrive:rclone-test-yovulez1buxa': not deleting directories as there were IO errors run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-yovulez1buxa'", Local "Local file system at /tmp/rclone771422369", Modify Window "1ms" --- PASS: TestSyncImmutable (4.88s) === RUN TestSyncIgnoreCase run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-yovulez1buxa'", Local "Local file system at /tmp/rclone771422369", Modify Window "1ms" 2025/04/30 17:02:23 DEBUG : EXISTING: md5 = 90ef503a118321eb4460a8103b02fdb5 OK 2025/04/30 17:02:24 DEBUG : existing: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/30 17:02:24 DEBUG : existing: Unchanged skipping 2025/04/30 17:02:24 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yovulez1buxa': Waiting for checks to finish 2025/04/30 17:02:24 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yovulez1buxa': Waiting for transfers to finish 2025/04/30 17:02:24 DEBUG : Waiting for deletions to finish 2025/04/30 17:02:24 INFO : There was nothing to transfer --- PASS: TestSyncIgnoreCase (3.27s) === RUN TestFixCase run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-yovulez1buxa'", Local "Local file system at /tmp/rclone771422369", Modify Window "1ms" sync_test.go:2635: Skipping test as local or remote are case-sensitive --- SKIP: TestFixCase (0.48s) === RUN TestMaxTransfer === RUN TestMaxTransfer/Hard run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-yovulez1buxa'", Local "Local file system at /tmp/rclone771422369", 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-yovulez1buxa'", Local "Local file system at /tmp/rclone771422369", 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-yovulez1buxa'", Local "Local file system at /tmp/rclone771422369", Modify Window "1ms" sync_test.go:2674: This test only runs on local --- PASS: TestMaxTransfer (1.42s) --- SKIP: TestMaxTransfer/Hard (0.42s) --- SKIP: TestMaxTransfer/Soft (0.57s) --- SKIP: TestMaxTransfer/Cautious (0.43s) === RUN TestSyncConcurrentDelete run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-yovulez1buxa'", Local "Local file system at /tmp/rclone771422369", Modify Window "1ms" 2025/04/30 17:02:28 DEBUG : both0: md5 = 6c4fa7065d49449e950707f1fd8734db OK 2025/04/30 17:02:30 DEBUG : only0: md5 = 07ff0c2677cadbf99ccb1ecee49dbc0b OK 2025/04/30 17:02:31 DEBUG : both1: md5 = 3b81d6d1b706fc720fc6f36282a9c161 OK 2025/04/30 17:02:33 DEBUG : only1: md5 = 1a568d0ea9014833ab1273543cf02fb9 OK 2025/04/30 17:02:34 DEBUG : both2: md5 = 56cbdb4f22af10a504b46e0e012e58fb OK 2025/04/30 17:02:36 DEBUG : only2: md5 = 060191ba3150ea627c22950dff56e133 OK 2025/04/30 17:02:37 DEBUG : both3: md5 = 263311fe2b1655c156ea5690cf772927 OK 2025/04/30 17:02:39 DEBUG : only3: md5 = afa28e31dd983249b08c894ba2d424e1 OK 2025/04/30 17:02:40 DEBUG : both4: md5 = b544b4d595c806c0917bf74cb859f05e OK 2025/04/30 17:02:42 DEBUG : only4: md5 = ecf5a2216de7cd3bdd70a73daa57914f OK 2025/04/30 17:02:43 DEBUG : both5: md5 = 4e4c028ecb6f292646fd4bde8a213b1b OK 2025/04/30 17:02:45 DEBUG : only5: md5 = 67bf827ba5be53169350d813fb1eb2eb OK 2025/04/30 17:02:46 DEBUG : both6: md5 = 182ac83ab0def015bf33f10e9e1d8fef OK 2025/04/30 17:02:48 DEBUG : only6: md5 = 09fe7b8ee19ce1945e55414dea3b0c60 OK 2025/04/30 17:02:49 DEBUG : both7: md5 = 604e119dcdd34acb4ef06a6f52d63d8c OK 2025/04/30 17:02:50 DEBUG : only7: md5 = d931ce7ead118d046034fedb5f2af814 OK 2025/04/30 17:02:52 DEBUG : both8: md5 = 1c52d55e5951a48e70c04a03c6a108cc OK 2025/04/30 17:02:53 DEBUG : only8: md5 = caea0aafdf607c89784068c67b7a32ec OK 2025/04/30 17:02:55 DEBUG : both9: md5 = 18f6073d08bf16e1fc27eea4986988ec OK 2025/04/30 17:02:56 DEBUG : only9: md5 = 9378b0131f038b20debddf2dc8e1a69c OK 2025/04/30 17:02:58 DEBUG : both10: md5 = 155a424669d42215b88d1d20634a29ac OK 2025/04/30 17:02:59 DEBUG : only10: md5 = 9bc98b92514bbc5948b1aaee0f34ef02 OK 2025/04/30 17:03:01 DEBUG : both11: md5 = 1248330c3b721fec7a0b4166b7007dd0 OK 2025/04/30 17:03:02 DEBUG : only11: md5 = f9a06568f648097c63def640c3fbf55c OK 2025/04/30 17:03:04 DEBUG : both12: md5 = 9c4eaac67b8a4a3e0bfb0a590cf1bfb3 OK 2025/04/30 17:03:05 DEBUG : only12: md5 = 709a13e1f046017209d8ea46ea30fe5c OK 2025/04/30 17:03:07 DEBUG : both13: md5 = 03439199296f3020565e5ebdf926bf52 OK 2025/04/30 17:03:08 DEBUG : only13: md5 = beb663d1b15d2a50d4e712403a26e5fb OK 2025/04/30 17:03:10 DEBUG : both14: md5 = 98e226d31472bfa735a0655f89b25fc9 OK 2025/04/30 17:03:11 DEBUG : only14: md5 = c7351554ab0358750e7c2331b6662de3 OK 2025/04/30 17:03:13 DEBUG : both15: md5 = 6634faf419d7db8a503bc655e9ac75c9 OK 2025/04/30 17:03:14 DEBUG : only15: md5 = a400aedc178d21f397062641856c5655 OK 2025/04/30 17:03:16 DEBUG : both16: md5 = 80895ed9d9abe1aa076799122f19c912 OK 2025/04/30 17:03:17 DEBUG : only16: md5 = b3376d352cabe44c26f9be86408832a1 OK 2025/04/30 17:03:19 DEBUG : both17: md5 = 75e5c5e05a7fd333f83208e24adb198c OK 2025/04/30 17:03:20 DEBUG : only17: md5 = 839583d3a7ba3e93836395ced6511ba1 OK 2025/04/30 17:03:21 DEBUG : both18: md5 = 17e99ae44cae053789ad3d1e05bf0907 OK 2025/04/30 17:03:23 DEBUG : only18: md5 = 9b8a9762047a704e70baf6cc4923ce62 OK 2025/04/30 17:03:24 DEBUG : both19: md5 = f05cef30786524a76bd11eb87d8ca426 OK 2025/04/30 17:03:25 DEBUG : only19: md5 = 1386e7fc26685a3f48e09ff812ac0f8c OK 2025/04/30 17:03:26 DEBUG : both1: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/30 17:03:26 DEBUG : both1: Unchanged skipping 2025/04/30 17:03:26 DEBUG : both10: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/30 17:03:26 DEBUG : both10: Unchanged skipping 2025/04/30 17:03:26 DEBUG : both11: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/30 17:03:26 DEBUG : both11: Unchanged skipping 2025/04/30 17:03:26 DEBUG : both12: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/30 17:03:26 DEBUG : both12: Unchanged skipping 2025/04/30 17:03:26 DEBUG : both13: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/30 17:03:26 DEBUG : both13: Unchanged skipping 2025/04/30 17:03:26 DEBUG : both14: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/30 17:03:26 DEBUG : both15: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/30 17:03:26 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yovulez1buxa': Waiting for checks to finish 2025/04/30 17:03:26 DEBUG : both16: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/30 17:03:26 DEBUG : both14: Unchanged skipping 2025/04/30 17:03:26 DEBUG : both17: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/30 17:03:26 DEBUG : both0: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/30 17:03:26 DEBUG : both16: Unchanged skipping 2025/04/30 17:03:26 DEBUG : both18: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/30 17:03:26 DEBUG : both17: Unchanged skipping 2025/04/30 17:03:26 DEBUG : both19: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/30 17:03:26 DEBUG : both18: Unchanged skipping 2025/04/30 17:03:26 DEBUG : both2: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/30 17:03:26 DEBUG : both15: Unchanged skipping 2025/04/30 17:03:26 DEBUG : both3: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/30 17:03:26 DEBUG : both2: Unchanged skipping 2025/04/30 17:03:26 DEBUG : both4: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/30 17:03:26 DEBUG : both3: Unchanged skipping 2025/04/30 17:03:26 DEBUG : both0: Unchanged skipping 2025/04/30 17:03:26 DEBUG : both6: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/30 17:03:26 DEBUG : both5: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/30 17:03:26 DEBUG : both19: Unchanged skipping 2025/04/30 17:03:26 DEBUG : both7: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/30 17:03:26 DEBUG : both6: Unchanged skipping 2025/04/30 17:03:26 DEBUG : both8: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/30 17:03:26 DEBUG : both8: Unchanged skipping 2025/04/30 17:03:26 DEBUG : both9: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/30 17:03:26 DEBUG : both5: Unchanged skipping 2025/04/30 17:03:26 DEBUG : both4: Unchanged skipping 2025/04/30 17:03:26 DEBUG : both7: Unchanged skipping 2025/04/30 17:03:26 DEBUG : both9: Unchanged skipping 2025/04/30 17:03:26 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yovulez1buxa': Waiting for transfers to finish 2025/04/30 17:03:26 DEBUG : Waiting for deletions to finish 2025/04/30 17:03:27 INFO : only1: Deleted 2025/04/30 17:03:27 INFO : only18: Deleted 2025/04/30 17:03:27 INFO : only13: Deleted 2025/04/30 17:03:27 INFO : only19: Deleted 2025/04/30 17:03:27 INFO : only2: Deleted 2025/04/30 17:03:27 INFO : only3: Deleted 2025/04/30 17:03:27 INFO : only0: Deleted 2025/04/30 17:03:27 INFO : only7: Deleted 2025/04/30 17:03:28 INFO : only11: Deleted 2025/04/30 17:03:28 INFO : only12: Deleted 2025/04/30 17:03:28 INFO : only10: Deleted 2025/04/30 17:03:28 INFO : only6: Deleted 2025/04/30 17:03:28 INFO : only9: Deleted 2025/04/30 17:03:28 INFO : only15: Deleted 2025/04/30 17:03:28 INFO : only14: Deleted 2025/04/30 17:03:28 INFO : only16: Deleted 2025/04/30 17:03:28 INFO : only4: Deleted 2025/04/30 17:03:29 INFO : only17: Deleted 2025/04/30 17:03:29 INFO : only5: Deleted 2025/04/30 17:03:29 INFO : only8: Deleted 2025/04/30 17:03:29 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-yovulez1buxa'", Local "Local file system at /tmp/rclone771422369", Modify Window "1ms" --- PASS: TestSyncConcurrentDelete (73.58s) === RUN TestSyncConcurrentTruncate run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-yovulez1buxa'", Local "Local file system at /tmp/rclone771422369", Modify Window "1ms" 2025/04/30 17:03:42 DEBUG : both0: md5 = ae899f1d11d6efb1a1e583dfd92f2c76 OK 2025/04/30 17:03:43 DEBUG : only0: md5 = 630a18ef18891ae717e1f2734c7ad5b8 OK 2025/04/30 17:03:45 DEBUG : both1: md5 = 4c992290a3cbb27113026ece29c89599 OK 2025/04/30 17:03:46 DEBUG : only1: md5 = 97894c87d12e89092874d4cfdfbb8adc OK 2025/04/30 17:03:48 DEBUG : both2: md5 = 795f6c35f4abcf968d8519b6c643a286 OK 2025/04/30 17:03:50 DEBUG : only2: md5 = 2bbd55a454e33d709e56310e12fd0aed OK 2025/04/30 17:03:51 DEBUG : both3: md5 = 0672d92c520b617a2dced5f6cf03e473 OK 2025/04/30 17:03:53 DEBUG : only3: md5 = 63a725ca3c3c789b50068cf1c4db6441 OK 2025/04/30 17:03:54 DEBUG : both4: md5 = 232f6db8668ee25f0105b4366720e416 OK 2025/04/30 17:03:56 DEBUG : only4: md5 = 9da3dede844766fb47289c3b5d3d838d OK 2025/04/30 17:03:57 DEBUG : both5: md5 = d7377718604a0f60b2c236a4bbde94ec OK 2025/04/30 17:03:59 DEBUG : only5: md5 = 10f5453b1713e9c6359cb1fbdd62301c OK 2025/04/30 17:04:00 DEBUG : both6: md5 = 8211b1172675a5919bae82dd62a8f8e7 OK 2025/04/30 17:04:02 DEBUG : only6: md5 = 28e2267a6bc43c4cd9dcc656461cf222 OK 2025/04/30 17:04:03 DEBUG : both7: md5 = d75f734688f4a903297225924964029b OK 2025/04/30 17:04:05 DEBUG : only7: md5 = 3e8436a30e84b139785da683434af0f6 OK 2025/04/30 17:04:06 DEBUG : both8: md5 = 2a16fdc2aa98c939a3277b7366c414b9 OK 2025/04/30 17:04:08 DEBUG : only8: md5 = 2e3a218c1d019a7e79e1f65d1bbbf1df OK 2025/04/30 17:04:09 DEBUG : both9: md5 = ae4c4ffe4ecd788667d648829f6dab0d OK 2025/04/30 17:04:11 DEBUG : only9: md5 = 83efd6478793477c872567dae3fe9cf1 OK 2025/04/30 17:04:12 DEBUG : both10: md5 = 2db894613b7b88b13af70b58e78f4894 OK 2025/04/30 17:04:14 DEBUG : only10: md5 = fd0cf3e703d01fdb1df2495af994d8ad OK 2025/04/30 17:04:15 DEBUG : both11: md5 = 7c5b28d6cd21c5e88d717ace9c5c063f OK 2025/04/30 17:04:17 DEBUG : only11: md5 = 8135d94d599a47a893fb4a59a369f2db OK 2025/04/30 17:04:18 DEBUG : both12: md5 = 97889d31364e9525eabc63c299a1dda6 OK 2025/04/30 17:04:19 DEBUG : only12: md5 = fed24fc8874a9c5efc3f1db389b8a3ec OK 2025/04/30 17:04:21 DEBUG : both13: md5 = cde48256b22d006defcc5b36d20c92a2 OK 2025/04/30 17:04:22 DEBUG : only13: md5 = dd690b6ca100d77e5aab606a781ce7f9 OK 2025/04/30 17:04:24 DEBUG : both14: md5 = 9e762ad240e539a66441a9ef65071ced OK 2025/04/30 17:04:26 DEBUG : only14: md5 = 623f09264ae88603ff04c414bfb611b0 OK 2025/04/30 17:04:27 DEBUG : both15: md5 = 6f866203cca69281cc15a0be425249bc OK 2025/04/30 17:04:29 DEBUG : only15: md5 = 16a1783469b258640cb3fbaf0aa92fa2 OK 2025/04/30 17:04:31 DEBUG : both16: md5 = b2b175995676f52a6c77c7cf9908bc7c OK 2025/04/30 17:04:32 DEBUG : only16: md5 = 1af3148c2b01572e7a490ba641804041 OK 2025/04/30 17:04:33 DEBUG : both17: md5 = 6e22e66135dc8be70ee45665d7545006 OK 2025/04/30 17:04:35 DEBUG : only17: md5 = 81376a6f9a9757b276949edbf9e51836 OK 2025/04/30 17:04:37 DEBUG : both18: md5 = f0908cc172cc397a4a20e47d9dead381 OK 2025/04/30 17:04:38 DEBUG : only18: md5 = 83b4dc3c2dd9ee13a26759f05cbe78b2 OK 2025/04/30 17:04:40 DEBUG : both19: md5 = 2ea9bc040c8ac91eef430e0d77bf85d0 OK 2025/04/30 17:04:41 DEBUG : only19: md5 = 35b3c3a5e72d0ba346b6a0e61a91d597 OK 2025/04/30 17:04:42 DEBUG : both1: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/30 17:04:42 DEBUG : both1: Unchanged skipping 2025/04/30 17:04:42 DEBUG : both11: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/30 17:04:42 DEBUG : both0: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/30 17:04:42 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yovulez1buxa': Waiting for checks to finish 2025/04/30 17:04:42 DEBUG : both12: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/30 17:04:42 DEBUG : both11: Unchanged skipping 2025/04/30 17:04:42 DEBUG : both13: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/30 17:04:42 DEBUG : both13: Unchanged skipping 2025/04/30 17:04:42 DEBUG : both14: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/30 17:04:42 DEBUG : both10: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/30 17:04:42 DEBUG : both0: Unchanged skipping 2025/04/30 17:04:42 DEBUG : both15: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/30 17:04:42 DEBUG : both15: Unchanged skipping 2025/04/30 17:04:42 DEBUG : both16: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/30 17:04:42 DEBUG : both16: Unchanged skipping 2025/04/30 17:04:42 DEBUG : both17: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/30 17:04:42 DEBUG : both12: Unchanged skipping 2025/04/30 17:04:42 DEBUG : both18: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/30 17:04:42 DEBUG : both18: Unchanged skipping 2025/04/30 17:04:42 DEBUG : both19: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/30 17:04:42 DEBUG : both14: Unchanged skipping 2025/04/30 17:04:42 DEBUG : both2: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/30 17:04:42 DEBUG : both2: Unchanged skipping 2025/04/30 17:04:42 DEBUG : both3: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/30 17:04:42 DEBUG : both3: Unchanged skipping 2025/04/30 17:04:42 DEBUG : both4: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/30 17:04:42 DEBUG : both4: Unchanged skipping 2025/04/30 17:04:42 DEBUG : both5: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/30 17:04:42 DEBUG : both5: Unchanged skipping 2025/04/30 17:04:42 DEBUG : both6: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/30 17:04:42 DEBUG : both6: Unchanged skipping 2025/04/30 17:04:42 DEBUG : both7: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/30 17:04:42 DEBUG : both7: Unchanged skipping 2025/04/30 17:04:42 DEBUG : both8: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/30 17:04:42 DEBUG : both8: Unchanged skipping 2025/04/30 17:04:42 DEBUG : both9: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/30 17:04:42 DEBUG : both9: Unchanged skipping 2025/04/30 17:04:42 DEBUG : only0: Sizes differ (src 0 vs dst 6) 2025/04/30 17:04:42 DEBUG : only1: Sizes differ (src 0 vs dst 6) 2025/04/30 17:04:42 DEBUG : only10: Sizes differ (src 0 vs dst 6) 2025/04/30 17:04:42 DEBUG : only11: Sizes differ (src 0 vs dst 6) 2025/04/30 17:04:42 DEBUG : only12: Sizes differ (src 0 vs dst 6) 2025/04/30 17:04:42 DEBUG : only13: Sizes differ (src 0 vs dst 6) 2025/04/30 17:04:42 DEBUG : only14: Sizes differ (src 0 vs dst 6) 2025/04/30 17:04:42 DEBUG : only15: Sizes differ (src 0 vs dst 6) 2025/04/30 17:04:42 DEBUG : only16: Sizes differ (src 0 vs dst 6) 2025/04/30 17:04:42 DEBUG : only17: Sizes differ (src 0 vs dst 6) 2025/04/30 17:04:42 DEBUG : only18: Sizes differ (src 0 vs dst 6) 2025/04/30 17:04:42 DEBUG : only19: Sizes differ (src 0 vs dst 6) 2025/04/30 17:04:42 DEBUG : only2: Sizes differ (src 0 vs dst 6) 2025/04/30 17:04:42 DEBUG : only3: Sizes differ (src 0 vs dst 6) 2025/04/30 17:04:42 DEBUG : only4: Sizes differ (src 0 vs dst 6) 2025/04/30 17:04:42 DEBUG : only5: Sizes differ (src 0 vs dst 6) 2025/04/30 17:04:42 DEBUG : only6: Sizes differ (src 0 vs dst 6) 2025/04/30 17:04:42 DEBUG : only7: Sizes differ (src 0 vs dst 6) 2025/04/30 17:04:42 DEBUG : only8: Sizes differ (src 0 vs dst 6) 2025/04/30 17:04:42 DEBUG : only9: Sizes differ (src 0 vs dst 6) 2025/04/30 17:04:42 DEBUG : both10: Unchanged skipping 2025/04/30 17:04:42 DEBUG : both17: Unchanged skipping 2025/04/30 17:04:42 DEBUG : both19: Unchanged skipping 2025/04/30 17:04:42 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yovulez1buxa': Waiting for transfers to finish 2025/04/30 17:04:43 DEBUG : only11: md5 = 9ae7693d8740fd756de97f868573a7cd OK 2025/04/30 17:04:43 INFO : only11: Copied (replaced existing) 2025/04/30 17:04:43 DEBUG : only1: md5 = 8a72ba9458b7ec1ac0832dae0df8f26a OK 2025/04/30 17:04:43 INFO : only1: Copied (replaced existing) 2025/04/30 17:04:43 DEBUG : only10: md5 = 0a956155c3961573e61ed50d19d1f650 OK 2025/04/30 17:04:43 INFO : only10: Copied (replaced existing) 2025/04/30 17:04:43 DEBUG : only0: md5 = f6fb3d9eee4725ad9bb6c44071c0afb2 OK 2025/04/30 17:04:43 INFO : only0: Copied (replaced existing) 2025/04/30 17:04:44 DEBUG : only13: md5 = b3d4b616a22db985b8715a2c238891c3 OK 2025/04/30 17:04:44 INFO : only13: Copied (replaced existing) 2025/04/30 17:04:44 DEBUG : only14: md5 = 515621650a52615024931f569b61948e OK 2025/04/30 17:04:44 INFO : only14: Copied (replaced existing) 2025/04/30 17:04:44 DEBUG : only15: md5 = 137e2b044b63b96d2129db7bda322c45 OK 2025/04/30 17:04:44 INFO : only15: Copied (replaced existing) 2025/04/30 17:04:44 DEBUG : only12: md5 = 47b80730b0a080a8e40c543b6e420419 OK 2025/04/30 17:04:44 INFO : only12: Copied (replaced existing) 2025/04/30 17:04:45 DEBUG : only16: md5 = 06a0cc30b55cf3a7dafdafaa3cf4b6a4 OK 2025/04/30 17:04:45 INFO : only16: Copied (replaced existing) 2025/04/30 17:04:45 DEBUG : only19: md5 = 86fe65c2ff24c50953a93718d6f56427 OK 2025/04/30 17:04:45 INFO : only19: Copied (replaced existing) 2025/04/30 17:04:46 DEBUG : only18: md5 = 2ba80519595cd627c2ff2647af96e9a8 OK 2025/04/30 17:04:46 INFO : only18: Copied (replaced existing) 2025/04/30 17:04:46 DEBUG : only17: md5 = 98a0222b0fd9e25d0f8bfad818c37964 OK 2025/04/30 17:04:46 INFO : only17: Copied (replaced existing) 2025/04/30 17:04:47 DEBUG : only3: md5 = 85c68f6ded52a7c8edcdccb691a82fd3 OK 2025/04/30 17:04:47 INFO : only3: Copied (replaced existing) 2025/04/30 17:04:47 DEBUG : only4: md5 = 3c06463d651b93bb604b0de3b55b0a55 OK 2025/04/30 17:04:47 INFO : only4: Copied (replaced existing) 2025/04/30 17:04:47 DEBUG : only2: md5 = 14d460d2654f248a5a8c8ddd22b5b166 OK 2025/04/30 17:04:47 INFO : only2: Copied (replaced existing) 2025/04/30 17:04:47 DEBUG : only5: md5 = 4821dd5c330604e29a67eac8b7bd8533 OK 2025/04/30 17:04:47 INFO : only5: Copied (replaced existing) 2025/04/30 17:04:48 DEBUG : only6: md5 = 6cb0ef36f1681a241529921f5b117789 OK 2025/04/30 17:04:48 INFO : only6: Copied (replaced existing) 2025/04/30 17:04:48 DEBUG : only7: md5 = c129674d116acc5ceb4269f836b488bb OK 2025/04/30 17:04:48 INFO : only7: Copied (replaced existing) 2025/04/30 17:04:48 DEBUG : only8: md5 = bb0f33499538bf0a95a92761fe7e7634 OK 2025/04/30 17:04:48 INFO : only8: Copied (replaced existing) 2025/04/30 17:04:48 DEBUG : only9: md5 = 534cf789480cf327deef43b06826c708 OK 2025/04/30 17:04:48 INFO : only9: Copied (replaced existing) 2025/04/30 17:04:48 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-yovulez1buxa'", Local "Local file system at /tmp/rclone771422369", Modify Window "1ms" --- PASS: TestSyncConcurrentTruncate (89.14s) === RUN TestNothingToTransferWithEmptyDirs run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-yovulez1buxa'", Local "Local file system at /tmp/rclone771422369", Modify Window "1ms" 2025/04/30 17:05:09 INFO : sub dir: Set directory modification time (using DirSetModTime) 2025/04/30 17:05:09 DEBUG : sub dir: Making directory with metadata 2025/04/30 17:05:10 INFO : sub dir: Made directory with metadata (mtime=2011-12-30T12:59:59Z) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-yovulez1buxa'", Local "Local file system at /tmp/rclone771422369", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-yovulez1buxa'", Local "Local file system at /tmp/rclone771422369", Modify Window "1ms" 2025/04/30 17:05:29 INFO : sub dir2: Set directory modification time (using DirSetModTime) 2025/04/30 17:05:30 INFO : sub dir2: Set directory modification time (using DirSetModTime) 2025/04/30 17:05:30 INFO : sub dirEmpty/sub dirEmpty2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2025/04/30 17:05:30 INFO : sub dirEmpty: Set directory modification time (using DirSetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-yovulez1buxa'", Local "Local file system at /tmp/rclone771422369", Modify Window "1ms" 2025/04/30 17:05:43 DEBUG : gcsdkq814sbtppue42dpsbg8ug: Rmdir: contains trashed file: "sjuo65gk5q3r1199jselk9k9o0" 2025/04/30 17:05:44 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/37qp6d1gohacv723ij3brofbu8/i24n0ln37pa2hv8pctddeuh73o: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" 2025/04/30 17:05:44 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/37qp6d1gohacv723ij3brofbu8: Rmdir: contains trashed file: "i24n0ln37pa2hv8pctddeuh73o" 2025/04/30 17:05:45 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "37qp6d1gohacv723ij3brofbu8" 2025/04/30 17:05:46 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak" 2025/04/30 17:05:47 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak" 2025/04/30 17:05:47 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak" 2025/04/30 17:05:48 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak" 2025/04/30 17:05:49 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/4r13oncfa2rsrr82oqhsqv24ns: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" 2025/04/30 17:05:50 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc: Rmdir: contains trashed file: "4r13oncfa2rsrr82oqhsqv24ns" 2025/04/30 17:05:50 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak" 2025/04/30 17:05:50 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestNothingToTransferWithEmptyDirs (43.16s) === RUN TestNothingToTransferWithoutEmptyDirs run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-yovulez1buxa'", Local "Local file system at /tmp/rclone771422369", Modify Window "1ms" 2025/04/30 17:05:53 INFO : sub dir: Set directory modification time (using DirSetModTime) 2025/04/30 17:05:53 DEBUG : sub dir: Making directory with metadata 2025/04/30 17:05:53 INFO : sub dir: Made directory with metadata (mtime=2011-12-30T12:59:59Z) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-yovulez1buxa'", Local "Local file system at /tmp/rclone771422369", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-yovulez1buxa'", Local "Local file system at /tmp/rclone771422369", Modify Window "1ms" 2025/04/30 17:06:16 INFO : sub dir2: Set directory modification time (using DirSetModTime) 2025/04/30 17:06:17 INFO : sub dir2: Set directory modification time (using DirSetModTime) 2025/04/30 17:06:17 INFO : sub dirEmpty/sub dirEmpty2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2025/04/30 17:06:17 INFO : sub dirEmpty: Set directory modification time (using DirSetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-yovulez1buxa'", Local "Local file system at /tmp/rclone771422369", Modify Window "1ms" 2025/04/30 17:06:29 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/37qp6d1gohacv723ij3brofbu8/i24n0ln37pa2hv8pctddeuh73o: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" 2025/04/30 17:06:29 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/37qp6d1gohacv723ij3brofbu8: Rmdir: contains trashed file: "i24n0ln37pa2hv8pctddeuh73o" 2025/04/30 17:06:30 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "37qp6d1gohacv723ij3brofbu8" 2025/04/30 17:06:31 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak" 2025/04/30 17:06:32 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak" 2025/04/30 17:06:33 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak" 2025/04/30 17:06:33 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak" 2025/04/30 17:06:34 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/4r13oncfa2rsrr82oqhsqv24ns: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" 2025/04/30 17:06:35 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc: Rmdir: contains trashed file: "4r13oncfa2rsrr82oqhsqv24ns" 2025/04/30 17:06:35 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak" 2025/04/30 17:06:36 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestNothingToTransferWithoutEmptyDirs (45.28s) PASS 2025/04/30 17:06:38 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yovulez1buxa': Purge remote "./sync.test -test.v -test.timeout 1h0m0s -remote TestCryptDrive: -verbose" - Finished OK in 16m0.819943155s (try 1/5)