"./sync.test -test.v -test.timeout 1h0m0s -remote TestCryptDrive: -verbose -fast-list" - Starting (try 1/5) 2025/05/23 05:23:28 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-dusorix4sahe" 2025/05/23 05:23:28 DEBUG : Using config file from "/home/rclone/.rclone.conf" 2025/05/23 05:23:28 DEBUG : Creating backend with remote "TestDrive:crypt/fii6k2ajsollg3rgnctuvi954tfqhghtln2rjn6esq5lrafat29g" 2025/05/23 05:23:28 DEBUG : TestDrive: Loaded invalid token from config file - ignoring 2025/05/23 05:23:28 DEBUG : Saving config "token" in section "TestDrive" of the config file 2025/05/23 05:23:28 DEBUG : TestDrive: Saved new token in config file 2025/05/23 05:23:29 DEBUG : Creating backend with remote "/tmp/rclone1671050868" === RUN TestPipe --- PASS: TestPipe (0.00s) === RUN TestPipeConcurrent --- PASS: TestPipeConcurrent (0.05s) === RUN TestPipeOrderBy === RUN TestPipeOrderBy/#00 === RUN TestPipeOrderBy/size === RUN TestPipeOrderBy/name === RUN TestPipeOrderBy/modtime === RUN TestPipeOrderBy/size,ascending === RUN TestPipeOrderBy/name,asc === RUN TestPipeOrderBy/modtime,ascending === RUN TestPipeOrderBy/size,descending === RUN TestPipeOrderBy/name,desc === RUN TestPipeOrderBy/modtime,descending === RUN TestPipeOrderBy/size,mixed,50 === RUN TestPipeOrderBy/size,mixed,51 --- PASS: TestPipeOrderBy (0.00s) --- PASS: TestPipeOrderBy/#00 (0.00s) --- PASS: TestPipeOrderBy/size (0.00s) --- PASS: TestPipeOrderBy/name (0.00s) --- PASS: TestPipeOrderBy/modtime (0.00s) --- PASS: TestPipeOrderBy/size,ascending (0.00s) --- PASS: TestPipeOrderBy/name,asc (0.00s) --- PASS: TestPipeOrderBy/modtime,ascending (0.00s) --- PASS: TestPipeOrderBy/size,descending (0.00s) --- PASS: TestPipeOrderBy/name,desc (0.00s) --- PASS: TestPipeOrderBy/modtime,descending (0.00s) --- PASS: TestPipeOrderBy/size,mixed,50 (0.00s) --- PASS: TestPipeOrderBy/size,mixed,51 (0.00s) === RUN TestNewLess === RUN TestNewLess/blankOK === RUN TestNewLess/tooManyParts === RUN TestNewLess/tooManyParts2 === RUN TestNewLess/badMixed === RUN TestNewLess/unknownComparison === RUN TestNewLess/unknownSortDirection === RUN TestNewLess/size === RUN TestNewLess/name === RUN TestNewLess/modtime === RUN TestNewLess/size,ascending === RUN TestNewLess/name,asc === RUN TestNewLess/modtime,ascending === RUN TestNewLess/size,descending === RUN TestNewLess/name,desc === RUN TestNewLess/modtime,descending === RUN TestNewLess/modtime,mixed === RUN TestNewLess/modtime,mixed,30 --- PASS: TestNewLess (0.00s) --- PASS: TestNewLess/blankOK (0.00s) --- PASS: TestNewLess/tooManyParts (0.00s) --- PASS: TestNewLess/tooManyParts2 (0.00s) --- PASS: TestNewLess/badMixed (0.00s) --- PASS: TestNewLess/unknownComparison (0.00s) --- PASS: TestNewLess/unknownSortDirection (0.00s) --- PASS: TestNewLess/size (0.00s) --- PASS: TestNewLess/name (0.00s) --- PASS: TestNewLess/modtime (0.00s) --- PASS: TestNewLess/size,ascending (0.00s) --- PASS: TestNewLess/name,asc (0.00s) --- PASS: TestNewLess/modtime,ascending (0.00s) --- PASS: TestNewLess/size,descending (0.00s) --- PASS: TestNewLess/name,desc (0.00s) --- PASS: TestNewLess/modtime,descending (0.00s) --- PASS: TestNewLess/modtime,mixed (0.00s) --- PASS: TestNewLess/modtime,mixed,30 (0.00s) === RUN TestRcCopy rc_test.go:16: Skipping test on non local remote --- SKIP: TestRcCopy (0.00s) === RUN TestRcMove rc_test.go:16: Skipping test on non local remote --- SKIP: TestRcMove (0.00s) === RUN TestRcSync rc_test.go:16: Skipping test on non local remote --- SKIP: TestRcSync (0.00s) === RUN TestCopyWithDryRun run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dusorix4sahe'", Local "Local file system at /tmp/rclone1671050868", Modify Window "1ms" 2025/05/23 05:23:30 DEBUG : Added delayed dir = "sub dir", newDst= 2025/05/23 05:23:30 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2025/05/23 05:23:30 NOTICE: sub dir/hello world: Skipped copy as --dry-run is set (size 11) 2025/05/23 05:23:30 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dusorix4sahe': Waiting for checks to finish 2025/05/23 05:23:30 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dusorix4sahe': Waiting for transfers to finish 2025/05/23 05:23:30 NOTICE: sub dir: Skipped set directory modification time as --dry-run is set run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dusorix4sahe'", Local "Local file system at /tmp/rclone1671050868", Modify Window "1ms" --- PASS: TestCopyWithDryRun (2.18s) === RUN TestCopy run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dusorix4sahe'", Local "Local file system at /tmp/rclone1671050868", Modify Window "1ms" 2025/05/23 05:23:31 INFO : sub dir: Set directory modification time (using DirSetModTime) 2025/05/23 05:23:31 DEBUG : Added delayed dir = "sub dir", newDst= 2025/05/23 05:23:31 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2025/05/23 05:23:31 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dusorix4sahe': Waiting for checks to finish 2025/05/23 05:23:31 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dusorix4sahe': Waiting for transfers to finish 2025/05/23 05:23:33 DEBUG : sub dir/hello world: md5 = 03048082b1fd46f5cc2c7924a3b36c1e OK 2025/05/23 05:23:33 INFO : sub dir/hello world: Copied (new) 2025/05/23 05:23:34 INFO : sub dir: Set directory modification time (using DirSetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dusorix4sahe'", Local "Local file system at /tmp/rclone1671050868", Modify Window "1ms" 2025/05/23 05:23:36 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestCopy (6.18s) === RUN TestCopyMetadata run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dusorix4sahe'", Local "Local file system at /tmp/rclone1671050868", Modify Window "1ms" 2025/05/23 05:23:37 DEBUG : metadata sub dir: Making directory with metadata 2025/05/23 05:23:37 INFO : metadata sub dir: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2025/05/23 05:23:37 DEBUG : empty metadata sub dir: Making directory with metadata 2025/05/23 05:23:37 INFO : empty metadata sub dir: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2025/05/23 05:23:37 DEBUG : Local file system at /tmp/rclone1671050868: File to upload is small (21 bytes), uploading instead of streaming 2025/05/23 05:23:37 DEBUG : metadata sub dir/hello metadata world: md5 = baa7a013449dbba2b1ed02b5cfb4e1a2 OK 2025/05/23 05:23:37 DEBUG : metadata sub dir/hello metadata world: Size and md5 of src and dst objects identical 2025/05/23 05:23:37 INFO : metadata sub dir: Set directory modification time (using DirSetModTime) 2025/05/23 05:23:38 DEBUG : Google drive root 'crypt/fii6k2ajsollg3rgnctuvi954tfqhghtln2rjn6esq5lrafat29g': Skipping btime metadata as can't update it on an existing file: 2025-05-23T05:23:37.631423548Z 2025/05/23 05:23:38 INFO : empty metadata sub dir: Updated directory metadata 2025/05/23 05:23:38 DEBUG : Google drive root 'crypt/fii6k2ajsollg3rgnctuvi954tfqhghtln2rjn6esq5lrafat29g': Skipping btime metadata as can't update it on an existing file: 2025-05-23T05:23:37.631423548Z 2025/05/23 05:23:39 INFO : metadata sub dir: Updated directory metadata 2025/05/23 05:23:39 DEBUG : metadata sub dir/hello metadata world: Need to transfer - File not found at Destination 2025/05/23 05:23:39 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dusorix4sahe': Waiting for checks to finish 2025/05/23 05:23:39 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dusorix4sahe': Waiting for transfers to finish 2025/05/23 05:23:40 DEBUG : metadata sub dir/hello metadata world: md5 = dadf8934de631b3d79aaad862b81c1e0 OK 2025/05/23 05:23:40 INFO : metadata sub dir/hello metadata world: Copied (new) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dusorix4sahe'", Local "Local file system at /tmp/rclone1671050868", Modify Window "1ms" 2025/05/23 05:23:43 DEBUG : fg45q1rm3kh00nmmkk4m6ihmrcnel1p7551kqhjr9bk2gtd2gbf0: Rmdir: contains trashed file: "dmuvulfij81f693ur0f1vvbvq9v6iscp56daas3m51n9li5e3470" --- PASS: TestCopyMetadata (7.79s) === RUN TestCopyMetadataNoEmptyDirs run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dusorix4sahe'", Local "Local file system at /tmp/rclone1671050868", Modify Window "1ms" 2025/05/23 05:23:45 DEBUG : metadata sub dir: Making directory with metadata 2025/05/23 05:23:45 INFO : metadata sub dir: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2025/05/23 05:23:45 DEBUG : empty metadata sub dir: Making directory with metadata 2025/05/23 05:23:45 INFO : empty metadata sub dir: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2025/05/23 05:23:45 DEBUG : Local file system at /tmp/rclone1671050868: File to upload is small (21 bytes), uploading instead of streaming 2025/05/23 05:23:45 DEBUG : metadata sub dir/hello metadata world: md5 = baa7a013449dbba2b1ed02b5cfb4e1a2 OK 2025/05/23 05:23:45 DEBUG : metadata sub dir/hello metadata world: Size and md5 of src and dst objects identical 2025/05/23 05:23:45 INFO : metadata sub dir: Set directory modification time (using DirSetModTime) 2025/05/23 05:23:45 DEBUG : Added delayed dir = "empty metadata sub dir", newDst= 2025/05/23 05:23:45 DEBUG : Added delayed dir = "metadata sub dir", newDst= 2025/05/23 05:23:45 DEBUG : metadata sub dir/hello metadata world: Need to transfer - File not found at Destination 2025/05/23 05:23:45 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dusorix4sahe': Waiting for checks to finish 2025/05/23 05:23:45 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dusorix4sahe': Waiting for transfers to finish 2025/05/23 05:23:47 DEBUG : metadata sub dir/hello metadata world: md5 = 7b976147bd144b9aa8dad0daf9275d81 OK 2025/05/23 05:23:47 INFO : metadata sub dir/hello metadata world: Copied (new) 2025/05/23 05:23:47 DEBUG : Google drive root 'crypt/fii6k2ajsollg3rgnctuvi954tfqhghtln2rjn6esq5lrafat29g': Skipping btime metadata as can't update it on an existing file: 2025-05-23T05:23:45.419440736Z 2025/05/23 05:23:48 INFO : metadata sub dir: Updated directory metadata run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dusorix4sahe'", Local "Local file system at /tmp/rclone1671050868", Modify Window "1ms" 2025/05/23 05:23:51 DEBUG : fg45q1rm3kh00nmmkk4m6ihmrcnel1p7551kqhjr9bk2gtd2gbf0: Rmdir: contains trashed file: "dmuvulfij81f693ur0f1vvbvq9v6iscp56daas3m51n9li5e3470" --- PASS: TestCopyMetadataNoEmptyDirs (6.85s) === RUN TestCopyMissingDirectory run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dusorix4sahe'", Local "Local file system at /tmp/rclone1671050868", Modify Window "1ms" 2025/05/23 05:23:52 DEBUG : Creating backend with remote "/non-existing" 2025/05/23 05:23:52 ERROR : Local file system at /non-existing: error reading source root directory: directory not found 2025/05/23 05:23:52 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dusorix4sahe': Waiting for checks to finish 2025/05/23 05:23:52 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dusorix4sahe': Waiting for transfers to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dusorix4sahe'", Local "Local file system at /tmp/rclone1671050868", Modify Window "1ms" --- PASS: TestCopyMissingDirectory (1.16s) === RUN TestCopyNoTraverse run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dusorix4sahe'", Local "Local file system at /tmp/rclone1671050868", Modify Window "1ms" 2025/05/23 05:23:53 DEBUG : Added delayed dir = "sub dir", newDst= 2025/05/23 05:23:53 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2025/05/23 05:23:53 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dusorix4sahe': Waiting for checks to finish 2025/05/23 05:23:53 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dusorix4sahe': Waiting for transfers to finish 2025/05/23 05:23:55 DEBUG : sub dir/hello world: md5 = fd55674d8c6db8089873d88a09e30090 OK 2025/05/23 05:23:55 INFO : sub dir/hello world: Copied (new) 2025/05/23 05:23:56 INFO : sub dir: Set directory modification time (using DirSetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dusorix4sahe'", Local "Local file system at /tmp/rclone1671050868", Modify Window "1ms" 2025/05/23 05:23:57 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestCopyNoTraverse (5.63s) === RUN TestCopyCheckFirst run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dusorix4sahe'", Local "Local file system at /tmp/rclone1671050868", Modify Window "1ms" 2025/05/23 05:23:59 INFO : Encrypted drive 'TestCryptDrive:rclone-test-dusorix4sahe': Running all checks before starting transfers 2025/05/23 05:23:59 DEBUG : Added delayed dir = "sub dir", newDst= 2025/05/23 05:23:59 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2025/05/23 05:23:59 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dusorix4sahe': Waiting for checks to finish 2025/05/23 05:23:59 INFO : Encrypted drive 'TestCryptDrive:rclone-test-dusorix4sahe': Checks finished, now starting transfers 2025/05/23 05:23:59 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dusorix4sahe': Waiting for transfers to finish 2025/05/23 05:24:01 DEBUG : sub dir/hello world: md5 = a10a6b7acfd0509b41f6cd62b7043d3e OK 2025/05/23 05:24:01 INFO : sub dir/hello world: Copied (new) 2025/05/23 05:24:02 INFO : sub dir: Set directory modification time (using DirSetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dusorix4sahe'", Local "Local file system at /tmp/rclone1671050868", Modify Window "1ms" 2025/05/23 05:24:03 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestCopyCheckFirst (5.96s) === RUN TestSyncNoTraverse run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dusorix4sahe'", Local "Local file system at /tmp/rclone1671050868", Modify Window "1ms" 2025/05/23 05:24:05 ERROR : Ignoring --no-traverse with sync 2025/05/23 05:24:05 DEBUG : Added delayed dir = "sub dir", newDst= 2025/05/23 05:24:05 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2025/05/23 05:24:05 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dusorix4sahe': Waiting for checks to finish 2025/05/23 05:24:05 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dusorix4sahe': Waiting for transfers to finish 2025/05/23 05:24:07 DEBUG : sub dir/hello world: md5 = b5a09d0facb11d82058b6cf10b9394b1 OK 2025/05/23 05:24:07 INFO : sub dir/hello world: Copied (new) 2025/05/23 05:24:07 DEBUG : Waiting for deletions to finish 2025/05/23 05:24:08 INFO : sub dir: Set directory modification time (using DirSetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dusorix4sahe'", Local "Local file system at /tmp/rclone1671050868", Modify Window "1ms" 2025/05/23 05:24:09 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestSyncNoTraverse (5.81s) === RUN TestCopyWithDepth run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dusorix4sahe'", Local "Local file system at /tmp/rclone1671050868", Modify Window "1ms" 2025/05/23 05:24:11 DEBUG : hello world2: Need to transfer - File not found at Destination 2025/05/23 05:24:11 DEBUG : Added delayed dir = "sub dir", newDst= 2025/05/23 05:24:11 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dusorix4sahe': Waiting for checks to finish 2025/05/23 05:24:11 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dusorix4sahe': Waiting for transfers to finish 2025/05/23 05:24:12 DEBUG : hello world2: md5 = 8cb62a87ff7e9ce2b85c8e966f0c655c OK 2025/05/23 05:24:12 INFO : hello world2: Copied (new) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dusorix4sahe'", Local "Local file system at /tmp/rclone1671050868", Modify Window "1ms" --- PASS: TestCopyWithDepth (3.09s) === RUN TestCopyWithFilesFrom run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dusorix4sahe'", Local "Local file system at /tmp/rclone1671050868", Modify Window "1ms" 2025/05/23 05:24:14 DEBUG : potato2: Need to transfer - File not found at Destination 2025/05/23 05:24:14 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dusorix4sahe': Waiting for checks to finish 2025/05/23 05:24:14 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dusorix4sahe': Waiting for transfers to finish 2025/05/23 05:24:15 DEBUG : potato2: md5 = d1d24dff92b30fb8776dc7bed82adf4d OK 2025/05/23 05:24:15 INFO : potato2: Copied (new) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dusorix4sahe'", Local "Local file system at /tmp/rclone1671050868", Modify Window "1ms" --- PASS: TestCopyWithFilesFrom (3.21s) === RUN TestCopyWithFilesFromAndNoTraverse run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dusorix4sahe'", Local "Local file system at /tmp/rclone1671050868", Modify Window "1ms" 2025/05/23 05:24:17 DEBUG : potato2: Need to transfer - File not found at Destination 2025/05/23 05:24:17 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dusorix4sahe': Waiting for checks to finish 2025/05/23 05:24:17 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dusorix4sahe': Waiting for transfers to finish 2025/05/23 05:24:18 DEBUG : potato2: md5 = 88ff84add148bb4a54b09e173765af2b OK 2025/05/23 05:24:18 INFO : potato2: Copied (new) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dusorix4sahe'", Local "Local file system at /tmp/rclone1671050868", Modify Window "1ms" --- PASS: TestCopyWithFilesFromAndNoTraverse (3.24s) === RUN TestCopyEmptyDirectories run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dusorix4sahe'", Local "Local file system at /tmp/rclone1671050868", Modify Window "1ms" 2025/05/23 05:24:20 DEBUG : sub dir2/sub sub dir2: Making directory with metadata 2025/05/23 05:24:20 INFO : sub dir2/sub sub dir2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2025/05/23 05:24:20 INFO : sub dir2: Set directory modification time (using DirSetModTime) 2025/05/23 05:24:20 INFO : sub dir: Set directory modification time (using DirSetModTime) 2025/05/23 05:24:20 DEBUG : sub dir: Making directory with metadata 2025/05/23 05:24:21 INFO : sub dir: Made directory with metadata (mtime=2001-02-03T04:05:06.499999999Z) 2025/05/23 05:24:21 DEBUG : sub dir2: Making directory with metadata 2025/05/23 05:24:22 INFO : sub dir2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2025/05/23 05:24:22 DEBUG : sub dir2/sub sub dir2: Making directory with metadata 2025/05/23 05:24:22 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2025/05/23 05:24:22 INFO : sub dir2/sub sub dir2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2025/05/23 05:24:22 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dusorix4sahe': Waiting for checks to finish 2025/05/23 05:24:22 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dusorix4sahe': Waiting for transfers to finish 2025/05/23 05:24:23 DEBUG : sub dir/hello world: md5 = f03361d73dcbcffaba717aed53bec37b OK 2025/05/23 05:24:23 INFO : sub dir/hello world: Copied (new) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dusorix4sahe'", Local "Local file system at /tmp/rclone1671050868", Modify Window "1ms" 2025/05/23 05:24:27 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc: Rmdir: contains trashed file: "cv6a9uf28ngrajena8kt5ijjn0" 2025/05/23 05:24:28 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestCopyEmptyDirectories (8.87s) === RUN TestCopyNoEmptyDirectories run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dusorix4sahe'", Local "Local file system at /tmp/rclone1671050868", Modify Window "1ms" 2025/05/23 05:24:29 INFO : sub dir2: Making directory 2025/05/23 05:24:29 DEBUG : sub dir2/sub sub dir2: Making directory with metadata 2025/05/23 05:24:29 INFO : sub dir2/sub sub dir2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2025/05/23 05:24:29 DEBUG : Added delayed dir = "sub dir", newDst= 2025/05/23 05:24:29 DEBUG : Added delayed dir = "sub dir2", newDst= 2025/05/23 05:24:29 DEBUG : Added delayed dir = "sub dir2/sub sub dir2", newDst= 2025/05/23 05:24:29 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2025/05/23 05:24:29 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dusorix4sahe': Waiting for checks to finish 2025/05/23 05:24:29 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dusorix4sahe': Waiting for transfers to finish 2025/05/23 05:24:31 DEBUG : sub dir/hello world: md5 = 45f6e174a347df0134c6385a355b4586 OK 2025/05/23 05:24:31 INFO : sub dir/hello world: Copied (new) 2025/05/23 05:24:32 INFO : sub dir: Set directory modification time (using DirSetModTime) 2025/05/23 05:24:33 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestCopyNoEmptyDirectories (5.28s) === RUN TestMoveEmptyDirectories run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dusorix4sahe'", Local "Local file system at /tmp/rclone1671050868", Modify Window "1ms" 2025/05/23 05:24:34 DEBUG : sub dir2: Making directory with metadata 2025/05/23 05:24:34 INFO : sub dir2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2025/05/23 05:24:34 DEBUG : sub dir: Making directory with metadata 2025/05/23 05:24:35 INFO : sub dir: Made directory with metadata (mtime=2025-05-23T05:24:34.523548803Z) 2025/05/23 05:24:35 DEBUG : sub dir2: Making directory with metadata 2025/05/23 05:24:36 INFO : sub dir2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2025/05/23 05:24:36 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2025/05/23 05:24:36 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dusorix4sahe': Waiting for checks to finish 2025/05/23 05:24:36 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dusorix4sahe': Waiting for transfers to finish 2025/05/23 05:24:37 DEBUG : sub dir/hello world: md5 = 1833e1ff289de88e8ed1669c763d270d OK 2025/05/23 05:24:37 INFO : sub dir/hello world: Copied (new) 2025/05/23 05:24:37 INFO : sub dir/hello world: Deleted run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dusorix4sahe'", Local "Local file system at /tmp/rclone1671050868", Modify Window "1ms" 2025/05/23 05:24:40 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestMoveEmptyDirectories (6.83s) === RUN TestSyncNoUpdateDirModtime run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dusorix4sahe'", Local "Local file system at /tmp/rclone1671050868", Modify Window "1ms" 2025/05/23 05:24:41 DEBUG : sub dir no update dir modtime: Making directory with metadata 2025/05/23 05:24:41 INFO : sub dir no update dir modtime: Made directory with metadata (mtime=2001-02-03T04:05:06.499999999Z) 2025/05/23 05:24:42 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dusorix4sahe': Waiting for checks to finish 2025/05/23 05:24:42 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dusorix4sahe': Waiting for transfers to finish 2025/05/23 05:24:42 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dusorix4sahe'", Local "Local file system at /tmp/rclone1671050868", Modify Window "1ms" --- PASS: TestSyncNoUpdateDirModtime (4.02s) === RUN TestMoveNoEmptyDirectories run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dusorix4sahe'", Local "Local file system at /tmp/rclone1671050868", Modify Window "1ms" 2025/05/23 05:24:45 INFO : sub dir2: Making directory 2025/05/23 05:24:45 DEBUG : Added delayed dir = "sub dir", newDst= 2025/05/23 05:24:45 DEBUG : Added delayed dir = "sub dir2", newDst= 2025/05/23 05:24:45 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2025/05/23 05:24:45 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dusorix4sahe': Waiting for checks to finish 2025/05/23 05:24:45 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dusorix4sahe': Waiting for transfers to finish 2025/05/23 05:24:47 DEBUG : sub dir/hello world: md5 = 71940662710ed5db899e522b61a3f9bc OK 2025/05/23 05:24:47 INFO : sub dir/hello world: Copied (new) 2025/05/23 05:24:47 INFO : sub dir/hello world: Deleted 2025/05/23 05:24:48 INFO : sub dir: Set directory modification time (using DirSetModTime) 2025/05/23 05:24:49 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestMoveNoEmptyDirectories (5.32s) === RUN TestSyncEmptyDirectories run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dusorix4sahe'", Local "Local file system at /tmp/rclone1671050868", Modify Window "1ms" 2025/05/23 05:24:50 DEBUG : sub dir2: Making directory with metadata 2025/05/23 05:24:50 INFO : sub dir2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2025/05/23 05:24:50 INFO : sub dir: Set directory modification time (using DirSetModTime) 2025/05/23 05:24:50 DEBUG : sub dir: Making directory with metadata 2025/05/23 05:24:51 INFO : sub dir: Made directory with metadata (mtime=2001-02-03T04:05:06.499999999Z) 2025/05/23 05:24:51 DEBUG : sub dir2: Making directory with metadata 2025/05/23 05:24:52 INFO : sub dir2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2025/05/23 05:24:52 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2025/05/23 05:24:52 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dusorix4sahe': Waiting for checks to finish 2025/05/23 05:24:52 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dusorix4sahe': Waiting for transfers to finish 2025/05/23 05:24:53 DEBUG : sub dir/hello world: md5 = 736c1f10d269ad0b3533d2748ca70383 OK 2025/05/23 05:24:53 INFO : sub dir/hello world: Copied (new) 2025/05/23 05:24:53 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dusorix4sahe'", Local "Local file system at /tmp/rclone1671050868", Modify Window "1ms" 2025/05/23 05:24:56 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestSyncEmptyDirectories (7.20s) === RUN TestSyncSetDelayedModTimes run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dusorix4sahe'", Local "Local file system at /tmp/rclone1671050868", Modify Window "1ms" sync_test.go:507: Backend doesn't have DirModTimeUpdatesOnWrite set --- SKIP: TestSyncSetDelayedModTimes (0.71s) === RUN TestSyncNoEmptyDirectories run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dusorix4sahe'", Local "Local file system at /tmp/rclone1671050868", Modify Window "1ms" 2025/05/23 05:24:58 INFO : sub dir2: Making directory 2025/05/23 05:24:58 DEBUG : Added delayed dir = "sub dir", newDst= 2025/05/23 05:24:58 DEBUG : Added delayed dir = "sub dir2", newDst= 2025/05/23 05:24:58 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2025/05/23 05:24:58 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dusorix4sahe': Waiting for checks to finish 2025/05/23 05:24:58 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dusorix4sahe': Waiting for transfers to finish 2025/05/23 05:25:01 DEBUG : sub dir/hello world: md5 = f0830574b8bfdc190414e976ecaa4952 OK 2025/05/23 05:25:01 INFO : sub dir/hello world: Copied (new) 2025/05/23 05:25:01 DEBUG : Waiting for deletions to finish 2025/05/23 05:25:01 INFO : sub dir: Set directory modification time (using DirSetModTime) 2025/05/23 05:25:03 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestSyncNoEmptyDirectories (5.25s) === RUN TestServerSideCopy run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dusorix4sahe'", Local "Local file system at /tmp/rclone1671050868", Modify Window "1ms" 2025/05/23 05:25:05 DEBUG : sub dir/hello world: md5 = 821791db96ff2e5a8dbcd39f4a4a8347 OK 2025/05/23 05:25:06 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-pededom3loba" 2025/05/23 05:25:06 DEBUG : Creating backend with remote "TestDrive:crypt/ac0kurmgmdsemshfq1hpr0kvtbffn28b9uol1jlmmteevmengmpg" sync_test.go:590: Server side copy (if possible) Encrypted drive 'TestCryptDrive:rclone-test-dusorix4sahe' -> Encrypted drive 'TestCryptDrive:rclone-test-pededom3loba' 2025/05/23 05:25:07 DEBUG : Added delayed dir = "sub dir", newDst= 2025/05/23 05:25:07 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2025/05/23 05:25:07 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pededom3loba': Waiting for checks to finish 2025/05/23 05:25:07 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pededom3loba': Waiting for transfers to finish 2025/05/23 05:25:10 INFO : sub dir/hello world: Copied (server-side copy) 2025/05/23 05:25:11 INFO : sub dir: Set directory modification time (using DirSetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dusorix4sahe'", Local "Local file system at /tmp/rclone1671050868", Modify Window "1ms" 2025/05/23 05:25:11 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pededom3loba': Purge remote 2025/05/23 05:25:13 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestServerSideCopy (10.39s) === RUN TestCopyOverSelf run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dusorix4sahe'", Local "Local file system at /tmp/rclone1671050868", Modify Window "1ms" 2025/05/23 05:25:16 DEBUG : sub dir/hello world: md5 = 2dea6c6b4423df11f95f839c7aa3c619 OK 2025/05/23 05:25:17 INFO : sub dir: Set directory modification time (using SetModTime) 2025/05/23 05:25:17 DEBUG : Added delayed dir = "sub dir", newDst=sub dir 2025/05/23 05:25:17 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dusorix4sahe': Waiting for checks to finish 2025/05/23 05:25:17 DEBUG : sub dir/hello world: Sizes differ (src 17 vs dst 11) 2025/05/23 05:25:17 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dusorix4sahe': Waiting for transfers to finish 2025/05/23 05:25:18 DEBUG : sub dir/hello world: md5 = 146b9bfcf9e636410933b002f731b2c6 OK 2025/05/23 05:25:18 INFO : sub dir/hello world: Copied (replaced existing) 2025/05/23 05:25:19 INFO : sub dir: Set directory modification time (using SetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dusorix4sahe'", Local "Local file system at /tmp/rclone1671050868", Modify Window "1ms" 2025/05/23 05:25:21 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestCopyOverSelf (7.90s) === RUN TestServerSideCopyOverSelf run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dusorix4sahe'", Local "Local file system at /tmp/rclone1671050868", Modify Window "1ms" 2025/05/23 05:25:24 DEBUG : sub dir/hello world: md5 = 12477cbb331ea921f7e61e5bad10f1d7 OK 2025/05/23 05:25:24 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-liwunuj3wiro" 2025/05/23 05:25:24 DEBUG : Creating backend with remote "TestDrive:crypt/605618h4o1pp256vd03oc4jvcc4m3gv1227jnh5v70fsec258gc0" sync_test.go:626: Server side copy (if possible) Encrypted drive 'TestCryptDrive:rclone-test-dusorix4sahe' -> Encrypted drive 'TestCryptDrive:rclone-test-liwunuj3wiro' 2025/05/23 05:25:26 DEBUG : Added delayed dir = "sub dir", newDst= 2025/05/23 05:25:26 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2025/05/23 05:25:26 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-liwunuj3wiro': Waiting for checks to finish 2025/05/23 05:25:26 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-liwunuj3wiro': Waiting for transfers to finish 2025/05/23 05:25:28 INFO : sub dir/hello world: Copied (server-side copy) 2025/05/23 05:25:29 INFO : sub dir: Set directory modification time (using DirSetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dusorix4sahe'", Local "Local file system at /tmp/rclone1671050868", Modify Window "1ms" 2025/05/23 05:25:30 DEBUG : sub dir/hello world: md5 = 74df5c602043bc72b526bdf283bba997 OK 2025/05/23 05:25:31 DEBUG : sub dir: Directory modification time the same (differ by 0s, within tolerance 1ms) 2025/05/23 05:25:31 DEBUG : Added delayed dir = "sub dir", newDst=sub dir 2025/05/23 05:25:31 DEBUG : sub dir/hello world: Sizes differ (src 17 vs dst 11) 2025/05/23 05:25:31 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-liwunuj3wiro': Waiting for checks to finish 2025/05/23 05:25:31 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-liwunuj3wiro': Waiting for transfers to finish 2025/05/23 05:25:33 INFO : sub dir/hello world: Copied (server-side copy) 2025/05/23 05:25:33 INFO : sub dir: Set directory modification time (using SetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dusorix4sahe'", Local "Local file system at /tmp/rclone1671050868", Modify Window "1ms" 2025/05/23 05:25:34 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-liwunuj3wiro': Purge remote 2025/05/23 05:25:35 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestServerSideCopyOverSelf (15.40s) === RUN TestMoveOverSelf run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dusorix4sahe'", Local "Local file system at /tmp/rclone1671050868", Modify Window "1ms" 2025/05/23 05:25:39 DEBUG : sub dir/hello world: md5 = d82252c720edf90a212a2ae7afe1c23b OK 2025/05/23 05:25:41 INFO : sub dir: Set directory modification time (using SetModTime) 2025/05/23 05:25:41 DEBUG : Added delayed dir = "sub dir", newDst=sub dir 2025/05/23 05:25:41 DEBUG : sub dir/hello world: Sizes differ (src 17 vs dst 11) 2025/05/23 05:25:41 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dusorix4sahe': Waiting for checks to finish 2025/05/23 05:25:41 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dusorix4sahe': Waiting for transfers to finish 2025/05/23 05:25:42 DEBUG : sub dir/hello world: md5 = da9cc65b57d097fbad794996a6c505ae OK 2025/05/23 05:25:42 INFO : sub dir/hello world: Copied (replaced existing) 2025/05/23 05:25:42 INFO : sub dir/hello world: Deleted 2025/05/23 05:25:42 INFO : sub dir: Set directory modification time (using SetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dusorix4sahe'", Local "Local file system at /tmp/rclone1671050868", Modify Window "1ms" 2025/05/23 05:25:44 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestMoveOverSelf (7.99s) === RUN TestServerSideMoveOverSelf run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dusorix4sahe'", Local "Local file system at /tmp/rclone1671050868", Modify Window "1ms" 2025/05/23 05:25:47 DEBUG : sub dir/hello world: md5 = a99d359f16d95326eda8bac198fbc3ce OK 2025/05/23 05:25:48 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-revakon6gavu" 2025/05/23 05:25:48 DEBUG : Creating backend with remote "TestDrive:crypt/nv4bm92jmsfjhgg5nusrfdeqhuqp77hrjdll41qtdd0bj4dpris0" sync_test.go:671: Server side copy (if possible) Encrypted drive 'TestCryptDrive:rclone-test-dusorix4sahe' -> Encrypted drive 'TestCryptDrive:rclone-test-revakon6gavu' 2025/05/23 05:25:53 DEBUG : Added delayed dir = "sub dir", newDst= 2025/05/23 05:25:53 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2025/05/23 05:25:53 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-revakon6gavu': Waiting for checks to finish 2025/05/23 05:25:53 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-revakon6gavu': Waiting for transfers to finish 2025/05/23 05:25:56 INFO : sub dir/hello world: Copied (server-side copy) 2025/05/23 05:25:56 INFO : sub dir: Set directory modification time (using DirSetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dusorix4sahe'", Local "Local file system at /tmp/rclone1671050868", Modify Window "1ms" 2025/05/23 05:25:58 DEBUG : sub dir/hello world: md5 = 45ab1a3e85ff994aae4b46ef5b8ca4a2 OK 2025/05/23 05:25:58 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-revakon6gavu': Using server-side directory move 2025/05/23 05:25:58 INFO : Encrypted drive 'TestCryptDrive:rclone-test-revakon6gavu': Server side directory move failed - fallback to file moves: can't copy directory - destination already exists 2025/05/23 05:25:59 DEBUG : sub dir: Directory modification time the same (differ by 0s, within tolerance 1ms) 2025/05/23 05:25:59 DEBUG : Added delayed dir = "sub dir", newDst=sub dir 2025/05/23 05:25:59 DEBUG : sub dir/hello world: Sizes differ (src 17 vs dst 11) 2025/05/23 05:25:59 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-revakon6gavu': Waiting for checks to finish 2025/05/23 05:25:59 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-revakon6gavu': Waiting for transfers to finish 2025/05/23 05:25:59 INFO : sub dir/hello world: Deleted 2025/05/23 05:26:00 INFO : sub dir/hello world: Moved (server-side) 2025/05/23 05:26:00 INFO : sub dir: Set directory modification time (using SetModTime) 2025/05/23 05:26:03 DEBUG : sub dir/hello world: md5 = cea1b5ab8aa4fa966e5ac75fedb98441 OK 2025/05/23 05:26:03 DEBUG : testing file moves 2025/05/23 05:26:05 DEBUG : sub dir: Directory modification time the same (differ by 0s, within tolerance 1ms) 2025/05/23 05:26:05 DEBUG : Added delayed dir = "sub dir", newDst=sub dir 2025/05/23 05:26:05 DEBUG : sub dir/hello world: Sizes differ (src 24 vs dst 17) 2025/05/23 05:26:05 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-revakon6gavu': Waiting for checks to finish 2025/05/23 05:26:05 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-revakon6gavu': Waiting for transfers to finish 2025/05/23 05:26:06 INFO : sub dir/hello world: Deleted 2025/05/23 05:26:06 INFO : sub dir/hello world: Moved (server-side) 2025/05/23 05:26:07 INFO : sub dir: Set directory modification time (using SetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dusorix4sahe'", Local "Local file system at /tmp/rclone1671050868", Modify Window "1ms" 2025/05/23 05:26:08 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-revakon6gavu': Purge remote --- PASS: TestServerSideMoveOverSelf (25.02s) === RUN TestCopyAfterDelete run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dusorix4sahe'", Local "Local file system at /tmp/rclone1671050868", Modify Window "1ms" 2025/05/23 05:26:12 DEBUG : sub dir/hello world: md5 = 0965babef2eb2633837aea1565fd2952 OK 2025/05/23 05:26:12 ERROR : : error listing: directory not found 2025/05/23 05:26:13 INFO : Local file system at /tmp/rclone1671050868: Making directory 2025/05/23 05:26:13 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dusorix4sahe': Waiting for checks to finish 2025/05/23 05:26:13 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dusorix4sahe': Waiting for transfers to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dusorix4sahe'", Local "Local file system at /tmp/rclone1671050868", Modify Window "1ms" 2025/05/23 05:26:15 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestCopyAfterDelete (5.67s) === RUN TestCopyRedownload run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dusorix4sahe'", Local "Local file system at /tmp/rclone1671050868", Modify Window "1ms" 2025/05/23 05:26:18 DEBUG : sub dir/hello world: md5 = cce689dc0c5f3029752614938fb6656e OK 2025/05/23 05:26:19 DEBUG : Added delayed dir = "sub dir", newDst= 2025/05/23 05:26:19 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2025/05/23 05:26:19 DEBUG : Local file system at /tmp/rclone1671050868: Waiting for checks to finish 2025/05/23 05:26:19 DEBUG : Local file system at /tmp/rclone1671050868: Waiting for transfers to finish 2025/05/23 05:26:20 DEBUG : sub dir/hello world.285f0a30.partial: renamed to: sub dir/hello world 2025/05/23 05:26:20 INFO : sub dir/hello world: Copied (new) 2025/05/23 05:26:20 INFO : sub dir: Set directory modification time (using DirSetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dusorix4sahe'", Local "Local file system at /tmp/rclone1671050868", Modify Window "1ms" 2025/05/23 05:26:21 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestCopyRedownload (6.28s) === RUN TestSyncBasedOnCheckSum run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dusorix4sahe'", Local "Local file system at /tmp/rclone1671050868", Modify Window "1ms" 2025/05/23 05:26:22 DEBUG : check sum: Need to transfer - File not found at Destination 2025/05/23 05:26:22 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dusorix4sahe': Waiting for checks to finish 2025/05/23 05:26:22 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dusorix4sahe': Waiting for transfers to finish 2025/05/23 05:26:24 DEBUG : check sum: md5 = c50ea7740e51878ab2e804824cd77604 OK 2025/05/23 05:26:24 INFO : check sum: Copied (new) 2025/05/23 05:26:24 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dusorix4sahe'", Local "Local file system at /tmp/rclone1671050868", Modify Window "1ms" 2025/05/23 05:26:24 NOTICE: Encrypted drive 'TestCryptDrive:rclone-test-dusorix4sahe': --checksum is in use but the source and destination have no hashes in common; falling back to --size-only 2025/05/23 05:26:24 DEBUG : check sum: Size of src and dst objects identical 2025/05/23 05:26:24 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dusorix4sahe': Waiting for checks to finish 2025/05/23 05:26:24 DEBUG : check sum: Unchanged skipping 2025/05/23 05:26:24 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dusorix4sahe': Waiting for transfers to finish 2025/05/23 05:26:24 DEBUG : Waiting for deletions to finish 2025/05/23 05:26:24 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dusorix4sahe'", Local "Local file system at /tmp/rclone1671050868", Modify Window "1ms" --- PASS: TestSyncBasedOnCheckSum (4.31s) === RUN TestSyncSizeOnly run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dusorix4sahe'", Local "Local file system at /tmp/rclone1671050868", Modify Window "1ms" 2025/05/23 05:26:27 DEBUG : sizeonly: Need to transfer - File not found at Destination 2025/05/23 05:26:27 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dusorix4sahe': Waiting for checks to finish 2025/05/23 05:26:27 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dusorix4sahe': Waiting for transfers to finish 2025/05/23 05:26:28 DEBUG : sizeonly: md5 = 24e4b0d5b9b9b0ccbadf20d713b027c3 OK 2025/05/23 05:26:28 INFO : sizeonly: Copied (new) 2025/05/23 05:26:28 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dusorix4sahe'", Local "Local file system at /tmp/rclone1671050868", Modify Window "1ms" 2025/05/23 05:26:28 DEBUG : sizeonly: Sizes identical 2025/05/23 05:26:28 DEBUG : sizeonly: Unchanged skipping 2025/05/23 05:26:28 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dusorix4sahe': Waiting for checks to finish 2025/05/23 05:26:28 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dusorix4sahe': Waiting for transfers to finish 2025/05/23 05:26:28 DEBUG : Waiting for deletions to finish 2025/05/23 05:26:28 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dusorix4sahe'", Local "Local file system at /tmp/rclone1671050868", Modify Window "1ms" --- PASS: TestSyncSizeOnly (4.10s) === RUN TestSyncIgnoreSize run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dusorix4sahe'", Local "Local file system at /tmp/rclone1671050868", Modify Window "1ms" 2025/05/23 05:26:31 DEBUG : ignore-size: Need to transfer - File not found at Destination 2025/05/23 05:26:31 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dusorix4sahe': Waiting for checks to finish 2025/05/23 05:26:31 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dusorix4sahe': Waiting for transfers to finish 2025/05/23 05:26:32 DEBUG : ignore-size: md5 = 68f1c654bff2213f474bfb641d9306f8 OK 2025/05/23 05:26:32 INFO : ignore-size: Copied (new) 2025/05/23 05:26:32 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dusorix4sahe'", Local "Local file system at /tmp/rclone1671050868", Modify Window "1ms" 2025/05/23 05:26:32 DEBUG : ignore-size: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/05/23 05:26:32 DEBUG : ignore-size: Unchanged skipping 2025/05/23 05:26:32 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dusorix4sahe': Waiting for checks to finish 2025/05/23 05:26:32 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dusorix4sahe': Waiting for transfers to finish 2025/05/23 05:26:32 DEBUG : Waiting for deletions to finish 2025/05/23 05:26:32 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dusorix4sahe'", Local "Local file system at /tmp/rclone1671050868", Modify Window "1ms" --- PASS: TestSyncIgnoreSize (4.05s) === RUN TestSyncIgnoreTimes run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dusorix4sahe'", Local "Local file system at /tmp/rclone1671050868", Modify Window "1ms" 2025/05/23 05:26:36 DEBUG : existing: md5 = df10415386ce16a2923c5081e99a1833 OK 2025/05/23 05:26:36 DEBUG : existing: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/05/23 05:26:36 DEBUG : existing: Unchanged skipping 2025/05/23 05:26:36 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dusorix4sahe': Waiting for checks to finish 2025/05/23 05:26:36 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dusorix4sahe': Waiting for transfers to finish 2025/05/23 05:26:36 DEBUG : Waiting for deletions to finish 2025/05/23 05:26:36 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dusorix4sahe'", Local "Local file system at /tmp/rclone1671050868", Modify Window "1ms" 2025/05/23 05:26:37 DEBUG : existing: Transferring unconditionally as --ignore-times is in use 2025/05/23 05:26:37 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dusorix4sahe': Waiting for checks to finish 2025/05/23 05:26:37 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dusorix4sahe': Waiting for transfers to finish 2025/05/23 05:26:38 DEBUG : existing: md5 = 24134afe20c946b93b5f0f5e33a052d1 OK 2025/05/23 05:26:38 INFO : existing: Copied (replaced existing) 2025/05/23 05:26:38 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dusorix4sahe'", Local "Local file system at /tmp/rclone1671050868", Modify Window "1ms" --- PASS: TestSyncIgnoreTimes (5.14s) === RUN TestSyncIgnoreExisting run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dusorix4sahe'", Local "Local file system at /tmp/rclone1671050868", Modify Window "1ms" 2025/05/23 05:26:40 DEBUG : existing: Need to transfer - File not found at Destination 2025/05/23 05:26:40 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dusorix4sahe': Waiting for checks to finish 2025/05/23 05:26:40 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dusorix4sahe': Waiting for transfers to finish 2025/05/23 05:26:41 DEBUG : existing: md5 = 9b258ebb86607e7732a989a5470c3025 OK 2025/05/23 05:26:41 INFO : existing: Copied (new) 2025/05/23 05:26:41 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dusorix4sahe'", Local "Local file system at /tmp/rclone1671050868", Modify Window "1ms" 2025/05/23 05:26:42 DEBUG : existing: Destination exists, skipping 2025/05/23 05:26:42 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dusorix4sahe': Waiting for checks to finish 2025/05/23 05:26:42 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dusorix4sahe': Waiting for transfers to finish 2025/05/23 05:26:42 DEBUG : Waiting for deletions to finish 2025/05/23 05:26:42 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dusorix4sahe'", Local "Local file system at /tmp/rclone1671050868", Modify Window "1ms" --- PASS: TestSyncIgnoreExisting (4.19s) === RUN TestSyncIgnoreErrors run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dusorix4sahe'", Local "Local file system at /tmp/rclone1671050868", Modify Window "1ms" 2025/05/23 05:26:46 DEBUG : b/potato: md5 = 1a637f1082268d65bdc1cd240ae3e8c2 OK 2025/05/23 05:26:48 DEBUG : c/non empty space: md5 = 192fd302fffc0bb518a685eb5a3daaa4 OK 2025/05/23 05:26:48 INFO : d: Making directory 2025/05/23 05:26:50 DEBUG : Added delayed dir = "a", newDst= 2025/05/23 05:26:50 INFO : c: Set directory modification time (using SetModTime) 2025/05/23 05:26:50 DEBUG : Added delayed dir = "c", newDst=c 2025/05/23 05:26:50 DEBUG : c/non empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/05/23 05:26:50 DEBUG : a/potato2: Need to transfer - File not found at Destination 2025/05/23 05:26:50 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dusorix4sahe': Waiting for checks to finish 2025/05/23 05:26:50 DEBUG : c/non empty space: Unchanged skipping 2025/05/23 05:26:50 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dusorix4sahe': Waiting for transfers to finish 2025/05/23 05:26:53 DEBUG : a/potato2: md5 = 7a80e204c533d2835c5aaa51e5403128 OK 2025/05/23 05:26:53 INFO : a/potato2: Copied (new) 2025/05/23 05:26:53 DEBUG : Waiting for deletions to finish 2025/05/23 05:26:53 INFO : b/potato: Deleted 2025/05/23 05:26:54 INFO : a: Set directory modification time (using DirSetModTime) 2025/05/23 05:26:54 INFO : d: Removing directory 2025/05/23 05:26:54 INFO : b: Removing directory 2025/05/23 05:26:54 DEBUG : 32d8ua6196mc1r7qkfog53rkg0: Rmdir: contains trashed file: "2m507n64kafsi59v9q71r281a4" 2025/05/23 05:26:55 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dusorix4sahe': deleted 2 directories run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dusorix4sahe'", Local "Local file system at /tmp/rclone1671050868", Modify Window "1ms" 2025/05/23 05:26:57 DEBUG : 3i9du405pfogq3ncai6pg7ouio: Rmdir: contains trashed file: "982d3pss7t5pn0il16r2foj31s" 2025/05/23 05:26:58 DEBUG : 2bsvlrk2ne1lfitm6tttcu0qt8: Rmdir: contains trashed file: "89l8renevh3mji1c8r1p7qn6tg" --- PASS: TestSyncIgnoreErrors (15.04s) === RUN TestSyncAfterChangingModtimeOnly run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dusorix4sahe'", Local "Local file system at /tmp/rclone1671050868", Modify Window "1ms" 2025/05/23 05:27:00 DEBUG : empty space: md5 = a02865452561cbc4a2b0bdf1d7968d14 OK 2025/05/23 05:27:01 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/05/23 05:27:01 NOTICE: empty space: Skipped copy as --dry-run is set (size 1) 2025/05/23 05:27:01 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dusorix4sahe': Waiting for checks to finish 2025/05/23 05:27:01 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dusorix4sahe': Waiting for transfers to finish 2025/05/23 05:27:01 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dusorix4sahe'", Local "Local file system at /tmp/rclone1671050868", Modify Window "1ms" 2025/05/23 05:27:01 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/05/23 05:27:01 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dusorix4sahe': Waiting for checks to finish 2025/05/23 05:27:01 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dusorix4sahe': Waiting for transfers to finish 2025/05/23 05:27:02 DEBUG : empty space: md5 = 4915346cf35eb803da2c030fdd880947 OK 2025/05/23 05:27:02 INFO : empty space: Copied (replaced existing) 2025/05/23 05:27:02 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dusorix4sahe'", Local "Local file system at /tmp/rclone1671050868", Modify Window "1ms" --- PASS: TestSyncAfterChangingModtimeOnly (5.38s) === RUN TestSyncAfterChangingModtimeOnlyWithNoUpdateModTime run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dusorix4sahe'", Local "Local file system at /tmp/rclone1671050868", Modify Window "1ms" sync_test.go:1016: Can't check this if no hashes supported --- PASS: TestSyncAfterChangingModtimeOnlyWithNoUpdateModTime (0.42s) === RUN TestSyncDoesntUpdateModtime run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dusorix4sahe'", Local "Local file system at /tmp/rclone1671050868", Modify Window "1ms" 2025/05/23 05:27:06 DEBUG : foo: md5 = deb6c315062e96c2a75c13ab4ba5f6fa OK 2025/05/23 05:27:06 DEBUG : foo: Modification times differ by -95456h54m52.624456789s: 2011-12-25 12:59:59.123456789 +0000 UTC, 2001-02-03 04:05:06.499 +0000 UTC 2025/05/23 05:27:06 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dusorix4sahe': Waiting for checks to finish 2025/05/23 05:27:06 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dusorix4sahe': Waiting for transfers to finish 2025/05/23 05:27:07 DEBUG : foo: md5 = f0fcbfdea9621866b199841d1a227cd6 OK 2025/05/23 05:27:07 INFO : foo: Copied (replaced existing) 2025/05/23 05:27:07 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dusorix4sahe'", Local "Local file system at /tmp/rclone1671050868", Modify Window "1ms" --- PASS: TestSyncDoesntUpdateModtime (4.53s) === RUN TestSyncAfterAddingAFile run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dusorix4sahe'", Local "Local file system at /tmp/rclone1671050868", Modify Window "1ms" 2025/05/23 05:27:10 DEBUG : empty space: md5 = f0ab18f7b7921e92413063a94ac1c1ae OK 2025/05/23 05:27:11 DEBUG : empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/05/23 05:27:11 DEBUG : potato: Need to transfer - File not found at Destination 2025/05/23 05:27:11 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dusorix4sahe': Waiting for checks to finish 2025/05/23 05:27:11 DEBUG : empty space: Unchanged skipping 2025/05/23 05:27:11 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dusorix4sahe': Waiting for transfers to finish 2025/05/23 05:27:12 DEBUG : potato: md5 = cbb6e649407b04cebf491958aa4417cc OK 2025/05/23 05:27:12 INFO : potato: Copied (new) 2025/05/23 05:27:12 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dusorix4sahe'", Local "Local file system at /tmp/rclone1671050868", Modify Window "1ms" --- PASS: TestSyncAfterAddingAFile (5.34s) === RUN TestSyncAfterChangingFilesSizeOnly run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dusorix4sahe'", Local "Local file system at /tmp/rclone1671050868", Modify Window "1ms" 2025/05/23 05:27:16 DEBUG : potato: md5 = 6f6cc8435dc31e6bb6b5866e6f67c0ef OK 2025/05/23 05:27:16 DEBUG : potato: Sizes differ (src 21 vs dst 60) 2025/05/23 05:27:16 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dusorix4sahe': Waiting for checks to finish 2025/05/23 05:27:16 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dusorix4sahe': Waiting for transfers to finish 2025/05/23 05:27:17 DEBUG : potato: md5 = 567bac2f7f479c70bf99cf5efd0fb175 OK 2025/05/23 05:27:17 INFO : potato: Copied (replaced existing) 2025/05/23 05:27:17 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dusorix4sahe'", Local "Local file system at /tmp/rclone1671050868", Modify Window "1ms" --- PASS: TestSyncAfterChangingFilesSizeOnly (4.39s) === RUN TestSyncAfterChangingContentsOnly run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dusorix4sahe'", Local "Local file system at /tmp/rclone1671050868", Modify Window "1ms" 2025/05/23 05:27:20 DEBUG : potato: md5 = c6ddc8505b2e17a3f97cdc363c040e73 OK 2025/05/23 05:27:21 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/05/23 05:27:21 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dusorix4sahe': Waiting for checks to finish 2025/05/23 05:27:21 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dusorix4sahe': Waiting for transfers to finish 2025/05/23 05:27:22 DEBUG : potato: md5 = e64ad641070da5399a02b0d700e92828 OK 2025/05/23 05:27:22 INFO : potato: Copied (replaced existing) 2025/05/23 05:27:22 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dusorix4sahe'", Local "Local file system at /tmp/rclone1671050868", Modify Window "1ms" --- PASS: TestSyncAfterChangingContentsOnly (4.73s) === RUN TestSyncAfterRemovingAFileAndAddingAFileDryRun run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dusorix4sahe'", Local "Local file system at /tmp/rclone1671050868", Modify Window "1ms" 2025/05/23 05:27:25 DEBUG : potato: md5 = f9d2e5a416c830ddfa305b23c78bc002 OK 2025/05/23 05:27:26 DEBUG : empty space: md5 = d72d77b9c667bb3b2b538f2104a3336a OK 2025/05/23 05:27:26 DEBUG : potato2: Need to transfer - File not found at Destination 2025/05/23 05:27:26 DEBUG : empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/05/23 05:27:26 DEBUG : empty space: Unchanged skipping 2025/05/23 05:27:26 NOTICE: potato2: Skipped copy as --dry-run is set (size 60) 2025/05/23 05:27:26 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dusorix4sahe': Waiting for checks to finish 2025/05/23 05:27:26 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dusorix4sahe': Waiting for transfers to finish 2025/05/23 05:27:26 DEBUG : Waiting for deletions to finish 2025/05/23 05:27:26 NOTICE: potato: Skipped delete as --dry-run is set (size 21) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dusorix4sahe'", Local "Local file system at /tmp/rclone1671050868", Modify Window "1ms" --- PASS: TestSyncAfterRemovingAFileAndAddingAFileDryRun (4.94s) === RUN TestSyncAfterRemovingAFileAndAddingAFile run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dusorix4sahe'", Local "Local file system at /tmp/rclone1671050868", Modify Window "1ms" 2025/05/23 05:27:30 DEBUG : potato: md5 = bac5cacda7c9c3de326dbf4d401dc4c8 OK 2025/05/23 05:27:31 DEBUG : empty space: md5 = 3f33bf011197ac9e9c97a7668f246510 OK 2025/05/23 05:27:32 DEBUG : potato2: Need to transfer - File not found at Destination 2025/05/23 05:27:32 DEBUG : empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/05/23 05:27:32 DEBUG : empty space: Unchanged skipping 2025/05/23 05:27:32 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dusorix4sahe': Waiting for checks to finish 2025/05/23 05:27:32 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dusorix4sahe': Waiting for transfers to finish 2025/05/23 05:27:33 DEBUG : potato2: md5 = 75599fed93192b57fbe5ff7e97a2f8df OK 2025/05/23 05:27:33 INFO : potato2: Copied (new) 2025/05/23 05:27:33 DEBUG : Waiting for deletions to finish 2025/05/23 05:27:33 INFO : potato: Deleted run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dusorix4sahe'", Local "Local file system at /tmp/rclone1671050868", Modify Window "1ms" --- PASS: TestSyncAfterRemovingAFileAndAddingAFile (7.14s) === RUN TestSyncAfterRemovingAFileAndAddingAFileSubDir run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dusorix4sahe'", Local "Local file system at /tmp/rclone1671050868", Modify Window "1ms" 2025/05/23 05:27:38 DEBUG : b/potato: md5 = 7033e50c1a4a8b4dd5ef05b422476ce1 OK 2025/05/23 05:27:40 DEBUG : c/non empty space: md5 = df0e99e69f2ec10942256f4048bd6384 OK 2025/05/23 05:27:40 INFO : d: Making directory 2025/05/23 05:27:41 INFO : d/e: Making directory 2025/05/23 05:27:43 DEBUG : Added delayed dir = "a", newDst= 2025/05/23 05:27:43 INFO : c: Set directory modification time (using SetModTime) 2025/05/23 05:27:43 DEBUG : Added delayed dir = "c", newDst=c 2025/05/23 05:27:43 DEBUG : a/potato2: Need to transfer - File not found at Destination 2025/05/23 05:27:43 DEBUG : c/non empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/05/23 05:27:43 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dusorix4sahe': Waiting for checks to finish 2025/05/23 05:27:43 DEBUG : c/non empty space: Unchanged skipping 2025/05/23 05:27:43 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dusorix4sahe': Waiting for transfers to finish 2025/05/23 05:27:45 DEBUG : a/potato2: md5 = ccb038d8ca3de36406a6bad9231beb97 OK 2025/05/23 05:27:45 INFO : a/potato2: Copied (new) 2025/05/23 05:27:45 DEBUG : Waiting for deletions to finish 2025/05/23 05:27:46 INFO : b/potato: Deleted 2025/05/23 05:27:46 INFO : a: Set directory modification time (using DirSetModTime) 2025/05/23 05:27:46 INFO : d/e: Removing directory 2025/05/23 05:27:47 INFO : d: Removing directory 2025/05/23 05:27:47 DEBUG : ka6id8d20d3s5ktapedlphgta8: Rmdir: contains trashed file: "r8sppajuabeak3sbgj2ak8vuf8" 2025/05/23 05:27:48 INFO : b: Removing directory 2025/05/23 05:27:48 DEBUG : 32d8ua6196mc1r7qkfog53rkg0: Rmdir: contains trashed file: "2m507n64kafsi59v9q71r281a4" 2025/05/23 05:27:48 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dusorix4sahe': deleted 3 directories run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dusorix4sahe'", Local "Local file system at /tmp/rclone1671050868", Modify Window "1ms" 2025/05/23 05:27:50 DEBUG : 3i9du405pfogq3ncai6pg7ouio: Rmdir: contains trashed file: "982d3pss7t5pn0il16r2foj31s" 2025/05/23 05:27:51 DEBUG : 2bsvlrk2ne1lfitm6tttcu0qt8: Rmdir: contains trashed file: "89l8renevh3mji1c8r1p7qn6tg" --- PASS: TestSyncAfterRemovingAFileAndAddingAFileSubDir (16.52s) === RUN TestSyncAfterRemovingAFileAndAddingAFileSubDirWithErrors run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dusorix4sahe'", Local "Local file system at /tmp/rclone1671050868", Modify Window "1ms" 2025/05/23 05:27:54 DEBUG : b/potato: md5 = 49e1853a185f0a8cec13e0630fbd4505 OK 2025/05/23 05:27:56 DEBUG : c/non empty space: md5 = 7ec5e1966e2201e9a34fba8891f8470d OK 2025/05/23 05:27:56 INFO : d: Making directory 2025/05/23 05:27:58 DEBUG : Added delayed dir = "a", newDst= 2025/05/23 05:27:59 INFO : c: Set directory modification time (using SetModTime) 2025/05/23 05:27:59 DEBUG : Added delayed dir = "c", newDst=c 2025/05/23 05:27:59 DEBUG : a/potato2: Need to transfer - File not found at Destination 2025/05/23 05:27:59 DEBUG : c/non empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/05/23 05:27:59 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dusorix4sahe': Waiting for checks to finish 2025/05/23 05:27:59 DEBUG : c/non empty space: Unchanged skipping 2025/05/23 05:27:59 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dusorix4sahe': Waiting for transfers to finish 2025/05/23 05:28:01 DEBUG : a/potato2: md5 = 5f53983ad5c2783468f9f76a58729864 OK 2025/05/23 05:28:01 INFO : a/potato2: Copied (new) 2025/05/23 05:28:01 ERROR : Encrypted drive 'TestCryptDrive:rclone-test-dusorix4sahe': not deleting files as there were IO errors 2025/05/23 05:28:01 INFO : a: Set directory modification time (using DirSetModTime) 2025/05/23 05:28:01 ERROR : Encrypted drive 'TestCryptDrive:rclone-test-dusorix4sahe': not deleting directories as there were IO errors run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dusorix4sahe'", Local "Local file system at /tmp/rclone1671050868", Modify Window "1ms" 2025/05/23 05:28:05 DEBUG : 3i9du405pfogq3ncai6pg7ouio: Rmdir: contains trashed file: "982d3pss7t5pn0il16r2foj31s" 2025/05/23 05:28:05 DEBUG : 32d8ua6196mc1r7qkfog53rkg0: Rmdir: contains trashed file: "2m507n64kafsi59v9q71r281a4" 2025/05/23 05:28:06 DEBUG : 2bsvlrk2ne1lfitm6tttcu0qt8: Rmdir: contains trashed file: "89l8renevh3mji1c8r1p7qn6tg" --- PASS: TestSyncAfterRemovingAFileAndAddingAFileSubDirWithErrors (14.81s) === RUN TestSyncDeleteAfter --- PASS: TestSyncDeleteAfter (0.00s) === RUN TestSyncDeleteDuring run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dusorix4sahe'", Local "Local file system at /tmp/rclone1671050868", Modify Window "1ms" 2025/05/23 05:28:08 DEBUG : potato: md5 = ded4b6e54dad2065cabdac837a583091 OK 2025/05/23 05:28:10 DEBUG : empty space: md5 = e53976d6f39b14e08c3b0c6f3e29c402 OK 2025/05/23 05:28:10 DEBUG : Waiting for deletions to finish 2025/05/23 05:28:10 DEBUG : potato2: Need to transfer - File not found at Destination 2025/05/23 05:28:10 DEBUG : empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/05/23 05:28:10 DEBUG : empty space: Unchanged skipping 2025/05/23 05:28:10 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dusorix4sahe': Waiting for checks to finish 2025/05/23 05:28:10 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dusorix4sahe': Waiting for transfers to finish 2025/05/23 05:28:11 INFO : potato: Deleted 2025/05/23 05:28:12 DEBUG : potato2: md5 = d46676a88857b31fe4fa04821267832e OK 2025/05/23 05:28:12 INFO : potato2: Copied (new) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dusorix4sahe'", Local "Local file system at /tmp/rclone1671050868", Modify Window "1ms" --- PASS: TestSyncDeleteDuring (6.68s) === RUN TestSyncDeleteBefore run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dusorix4sahe'", Local "Local file system at /tmp/rclone1671050868", Modify Window "1ms" 2025/05/23 05:28:15 DEBUG : potato: md5 = 95f13e4525e57069349ae1b22b04073f OK 2025/05/23 05:28:17 DEBUG : empty space: md5 = 15135dcc546f7115b144212d511824b2 OK 2025/05/23 05:28:17 DEBUG : Waiting for deletions to finish 2025/05/23 05:28:17 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dusorix4sahe': Waiting for checks to finish 2025/05/23 05:28:17 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dusorix4sahe': Waiting for transfers to finish 2025/05/23 05:28:18 INFO : potato: Deleted 2025/05/23 05:28:18 DEBUG : empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/05/23 05:28:18 DEBUG : potato2: Need to transfer - File not found at Destination 2025/05/23 05:28:18 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dusorix4sahe': Waiting for checks to finish 2025/05/23 05:28:18 DEBUG : empty space: Unchanged skipping 2025/05/23 05:28:18 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dusorix4sahe': Waiting for transfers to finish 2025/05/23 05:28:19 DEBUG : potato2: md5 = f9693c8fb252752faccbd3382c1452b4 OK 2025/05/23 05:28:19 INFO : potato2: Copied (new) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dusorix4sahe'", Local "Local file system at /tmp/rclone1671050868", Modify Window "1ms" --- PASS: TestSyncDeleteBefore (7.81s) === RUN TestCopyDeleteBefore run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dusorix4sahe'", Local "Local file system at /tmp/rclone1671050868", Modify Window "1ms" 2025/05/23 05:28:23 DEBUG : potato: md5 = f6f472c09582f900d52534b56992e999 OK 2025/05/23 05:28:23 DEBUG : potato2: Need to transfer - File not found at Destination 2025/05/23 05:28:23 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dusorix4sahe': Waiting for checks to finish 2025/05/23 05:28:23 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dusorix4sahe': Waiting for transfers to finish 2025/05/23 05:28:25 DEBUG : potato2: md5 = 73f5aa8b2f8978778384efa65317b777 OK 2025/05/23 05:28:25 INFO : potato2: Copied (new) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dusorix4sahe'", Local "Local file system at /tmp/rclone1671050868", Modify Window "1ms" --- PASS: TestCopyDeleteBefore (5.50s) === RUN TestSyncWithExclude run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dusorix4sahe'", Local "Local file system at /tmp/rclone1671050868", Modify Window "1ms" 2025/05/23 05:28:28 DEBUG : potato2: md5 = 559565ea733654e31e2aabcbdf24f5f8 OK 2025/05/23 05:28:30 DEBUG : empty space: md5 = 2cb3b19abf9db51a5d040d06bcd7c719 OK 2025/05/23 05:28:30 DEBUG : enormous: Excluded (Size Filter) 2025/05/23 05:28:30 DEBUG : enormous: Excluded 2025/05/23 05:28:30 DEBUG : potato2: Excluded (Size Filter) 2025/05/23 05:28:30 DEBUG : potato2: Excluded 2025/05/23 05:28:30 DEBUG : potato2: Excluded (Size Filter) 2025/05/23 05:28:30 DEBUG : empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/05/23 05:28:30 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dusorix4sahe': Waiting for checks to finish 2025/05/23 05:28:30 DEBUG : empty space: Unchanged skipping 2025/05/23 05:28:30 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dusorix4sahe': Waiting for transfers to finish 2025/05/23 05:28:30 DEBUG : Waiting for deletions to finish 2025/05/23 05:28:30 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dusorix4sahe'", Local "Local file system at /tmp/rclone1671050868", Modify Window "1ms" 2025/05/23 05:28:31 DEBUG : enormous: Excluded (Size Filter) 2025/05/23 05:28:31 DEBUG : enormous: Excluded 2025/05/23 05:28:31 DEBUG : potato2: Excluded (Size Filter) 2025/05/23 05:28:31 DEBUG : potato2: Excluded 2025/05/23 05:28:31 DEBUG : potato2: Excluded (Size Filter) 2025/05/23 05:28:31 DEBUG : Local file system at /tmp/rclone1671050868: Waiting for checks to finish 2025/05/23 05:28:31 DEBUG : empty space: Size and modification time the same (differ by 456.789µs, within tolerance 1ms) 2025/05/23 05:28:31 DEBUG : empty space: Unchanged skipping 2025/05/23 05:28:31 DEBUG : Local file system at /tmp/rclone1671050868: Waiting for transfers to finish 2025/05/23 05:28:31 DEBUG : Waiting for deletions to finish 2025/05/23 05:28:31 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dusorix4sahe'", Local "Local file system at /tmp/rclone1671050868", Modify Window "1ms" --- PASS: TestSyncWithExclude (6.08s) === RUN TestSyncWithExcludeAndDeleteExcluded run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dusorix4sahe'", Local "Local file system at /tmp/rclone1671050868", Modify Window "1ms" 2025/05/23 05:28:34 DEBUG : potato2: md5 = 55d860d1a940aee640cade39b3784388 OK 2025/05/23 05:28:36 DEBUG : empty space: md5 = 8394591ea3527b61ba4b8b94ed872dd6 OK 2025/05/23 05:28:37 DEBUG : enormous: md5 = 3c5007661599947f0033ebd29697142e OK 2025/05/23 05:28:38 DEBUG : enormous: Excluded (Size Filter) 2025/05/23 05:28:38 DEBUG : enormous: Excluded 2025/05/23 05:28:38 DEBUG : potato2: Excluded (Size Filter) 2025/05/23 05:28:38 DEBUG : potato2: Excluded 2025/05/23 05:28:38 DEBUG : empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/05/23 05:28:38 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dusorix4sahe': Waiting for checks to finish 2025/05/23 05:28:38 DEBUG : empty space: Unchanged skipping 2025/05/23 05:28:38 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dusorix4sahe': Waiting for transfers to finish 2025/05/23 05:28:38 DEBUG : Waiting for deletions to finish 2025/05/23 05:28:38 INFO : enormous: Deleted 2025/05/23 05:28:38 INFO : potato2: Deleted 2025/05/23 05:28:38 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dusorix4sahe'", Local "Local file system at /tmp/rclone1671050868", Modify Window "1ms" 2025/05/23 05:28:39 DEBUG : empty space: Size and modification time the same (differ by 456.789µs, within tolerance 1ms) 2025/05/23 05:28:39 DEBUG : empty space: Unchanged skipping 2025/05/23 05:28:39 DEBUG : Local file system at /tmp/rclone1671050868: Waiting for checks to finish 2025/05/23 05:28:39 DEBUG : Local file system at /tmp/rclone1671050868: Waiting for transfers to finish 2025/05/23 05:28:39 DEBUG : Waiting for deletions to finish 2025/05/23 05:28:39 INFO : enormous: Deleted 2025/05/23 05:28:39 INFO : potato2: Deleted 2025/05/23 05:28:39 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dusorix4sahe'", Local "Local file system at /tmp/rclone1671050868", Modify Window "1ms" --- PASS: TestSyncWithExcludeAndDeleteExcluded (7.49s) === RUN TestSyncWithUpdateOlder run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dusorix4sahe'", Local "Local file system at /tmp/rclone1671050868", Modify Window "1ms" 2025/05/23 05:28:42 DEBUG : one: md5 = 08ea30387088a9eb50b4baea81d25291 OK 2025/05/23 05:28:43 DEBUG : two: md5 = 5948bf0f70ec60935269c8e86dc45a1e OK 2025/05/23 05:28:44 DEBUG : three: md5 = bbdfdbe616da0807576d545066e735ea OK 2025/05/23 05:28:46 DEBUG : four: md5 = c728754e357fd4c6ddf7d054d35aac80 OK 2025/05/23 05:28:46 DEBUG : five: Need to transfer - File not found at Destination 2025/05/23 05:28:46 DEBUG : four: Sizes differ (src 4 vs dst 8) 2025/05/23 05:28:46 DEBUG : one: Destination is newer than source, skipping 2025/05/23 05:28:46 DEBUG : three: Sizes identical 2025/05/23 05:28:46 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dusorix4sahe': Waiting for checks to finish 2025/05/23 05:28:46 DEBUG : four: Destination mod time is within 1s of source but files differ, transferring 2025/05/23 05:28:46 DEBUG : three: Destination mod time is within 1s of source and files identical, skipping 2025/05/23 05:28:46 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dusorix4sahe': Waiting for transfers to finish 2025/05/23 05:28:47 DEBUG : four: md5 = 0ff1ad0e49ed217cb882e1edefb4e743 OK 2025/05/23 05:28:47 INFO : four: Copied (replaced existing) 2025/05/23 05:28:47 DEBUG : two: md5 = 9d83e9dca6cba57e81935df37fff35f0 OK 2025/05/23 05:28:47 INFO : two: Copied (replaced existing) 2025/05/23 05:28:47 DEBUG : five: md5 = 3127c439b93cf604de47105521484c89 OK 2025/05/23 05:28:47 INFO : five: Copied (new) 2025/05/23 05:28:47 DEBUG : Waiting for deletions to finish sync_test.go:1449: Skip test with --checksum as no hashes supported --- PASS: TestSyncWithUpdateOlder (9.87s) === 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-dusorix4sahe'", Local "Local file system at /tmp/rclone1671050868", Modify Window "1ms" sync_test.go:1538: Can track renames: false 2025/05/23 05:28:50 ERROR : Encrypted drive 'TestCryptDrive:rclone-test-dusorix4sahe': Ignoring --track-renames as the source and destination do not have a common hash 2025/05/23 05:28:51 DEBUG : potato: Need to transfer - File not found at Destination 2025/05/23 05:28:51 DEBUG : yam: Need to transfer - File not found at Destination 2025/05/23 05:28:51 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dusorix4sahe': Waiting for checks to finish 2025/05/23 05:28:51 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dusorix4sahe': Waiting for transfers to finish 2025/05/23 05:28:52 DEBUG : potato: md5 = f2f8b584fa59aa35735229df74ba8ddb OK 2025/05/23 05:28:52 INFO : potato: Copied (new) 2025/05/23 05:28:52 DEBUG : yam: md5 = 14f22c53288da4792292282839f9e987 OK 2025/05/23 05:28:52 INFO : yam: Copied (new) 2025/05/23 05:28:52 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dusorix4sahe'", Local "Local file system at /tmp/rclone1671050868", Modify Window "1ms" 2025/05/23 05:28:52 ERROR : Encrypted drive 'TestCryptDrive:rclone-test-dusorix4sahe': Ignoring --track-renames as the source and destination do not have a common hash 2025/05/23 05:28:53 DEBUG : potato: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/05/23 05:28:53 DEBUG : yaml: Need to transfer - File not found at Destination 2025/05/23 05:28:53 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dusorix4sahe': Waiting for checks to finish 2025/05/23 05:28:53 DEBUG : potato: Unchanged skipping 2025/05/23 05:28:53 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dusorix4sahe': Waiting for transfers to finish 2025/05/23 05:28:54 DEBUG : yaml: md5 = 2e8de7a9b222d10b57528fccaadf0fd3 OK 2025/05/23 05:28:54 INFO : yaml: Copied (new) 2025/05/23 05:28:54 DEBUG : Waiting for deletions to finish 2025/05/23 05:28:55 INFO : yam: Deleted run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dusorix4sahe'", Local "Local file system at /tmp/rclone1671050868", Modify Window "1ms" --- PASS: TestSyncWithTrackRenames (6.60s) === RUN TestParseRenamesStrategyModtime --- PASS: TestParseRenamesStrategyModtime (0.00s) === RUN TestRenamesStrategyModtime --- PASS: TestRenamesStrategyModtime (0.00s) === RUN TestSyncWithTrackRenamesStrategyModtime run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dusorix4sahe'", Local "Local file system at /tmp/rclone1671050868", Modify Window "1ms" sync_test.go:1610: Can track renames: true 2025/05/23 05:28:57 INFO : Encrypted drive 'TestCryptDrive:rclone-test-dusorix4sahe': Making map for --track-renames 2025/05/23 05:28:57 INFO : Encrypted drive 'TestCryptDrive:rclone-test-dusorix4sahe': Finished making map for --track-renames 2025/05/23 05:28:57 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dusorix4sahe': Waiting for checks to finish 2025/05/23 05:28:57 DEBUG : potato: Need to transfer - No matching file found at Destination 2025/05/23 05:28:57 DEBUG : yam: Need to transfer - No matching file found at Destination 2025/05/23 05:28:57 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dusorix4sahe': Waiting for renames to finish 2025/05/23 05:28:57 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dusorix4sahe': Waiting for transfers to finish 2025/05/23 05:28:58 DEBUG : potato: md5 = 09f2b09e17a663d60be6069b9955b48e OK 2025/05/23 05:28:58 INFO : potato: Copied (new) 2025/05/23 05:28:59 DEBUG : yam: md5 = 85a527d70e092e386967b7b14d789639 OK 2025/05/23 05:28:59 INFO : yam: Copied (new) 2025/05/23 05:28:59 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dusorix4sahe'", Local "Local file system at /tmp/rclone1671050868", Modify Window "1ms" 2025/05/23 05:28:59 DEBUG : potato: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/05/23 05:28:59 INFO : Encrypted drive 'TestCryptDrive:rclone-test-dusorix4sahe': Making map for --track-renames 2025/05/23 05:28:59 INFO : Encrypted drive 'TestCryptDrive:rclone-test-dusorix4sahe': Finished making map for --track-renames 2025/05/23 05:28:59 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dusorix4sahe': Waiting for checks to finish 2025/05/23 05:28:59 DEBUG : potato: Unchanged skipping 2025/05/23 05:28:59 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dusorix4sahe': Waiting for renames to finish 2025/05/23 05:29:00 INFO : yam: Moved (server-side) to: yaml 2025/05/23 05:29:00 INFO : yaml: Renamed from "yam" 2025/05/23 05:29:00 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dusorix4sahe': Waiting for transfers to finish 2025/05/23 05:29:00 DEBUG : Waiting for deletions to finish 2025/05/23 05:29:00 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dusorix4sahe'", Local "Local file system at /tmp/rclone1671050868", Modify Window "1ms" --- PASS: TestSyncWithTrackRenamesStrategyModtime (5.13s) === RUN TestSyncWithTrackRenamesStrategyLeaf run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dusorix4sahe'", Local "Local file system at /tmp/rclone1671050868", Modify Window "1ms" sync_test.go:1649: Can track renames: true 2025/05/23 05:29:02 DEBUG : Added delayed dir = "sub", newDst= 2025/05/23 05:29:02 INFO : Encrypted drive 'TestCryptDrive:rclone-test-dusorix4sahe': Making map for --track-renames 2025/05/23 05:29:02 INFO : Encrypted drive 'TestCryptDrive:rclone-test-dusorix4sahe': Finished making map for --track-renames 2025/05/23 05:29:02 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dusorix4sahe': Waiting for checks to finish 2025/05/23 05:29:02 DEBUG : potato: Need to transfer - No matching file found at Destination 2025/05/23 05:29:02 DEBUG : sub/yam: Need to transfer - No matching file found at Destination 2025/05/23 05:29:02 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dusorix4sahe': Waiting for renames to finish 2025/05/23 05:29:02 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dusorix4sahe': Waiting for transfers to finish 2025/05/23 05:29:04 DEBUG : sub/yam: md5 = 9be82afa5ea6bd505dd5a801fc2b9097 OK 2025/05/23 05:29:04 INFO : sub/yam: Copied (new) 2025/05/23 05:29:04 DEBUG : potato: md5 = 3dac9c98cf624b1301999953229ce49c OK 2025/05/23 05:29:04 INFO : potato: Copied (new) 2025/05/23 05:29:04 DEBUG : Waiting for deletions to finish 2025/05/23 05:29:05 INFO : sub: Set directory modification time (using DirSetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dusorix4sahe'", Local "Local file system at /tmp/rclone1671050868", Modify Window "1ms" 2025/05/23 05:29:06 DEBUG : potato: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/05/23 05:29:06 DEBUG : potato: Unchanged skipping 2025/05/23 05:29:06 INFO : sub: Set directory modification time (using SetModTime) 2025/05/23 05:29:06 DEBUG : Added delayed dir = "sub", newDst=sub 2025/05/23 05:29:06 INFO : Encrypted drive 'TestCryptDrive:rclone-test-dusorix4sahe': Making map for --track-renames 2025/05/23 05:29:06 INFO : Encrypted drive 'TestCryptDrive:rclone-test-dusorix4sahe': Finished making map for --track-renames 2025/05/23 05:29:06 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dusorix4sahe': Waiting for checks to finish 2025/05/23 05:29:06 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dusorix4sahe': Waiting for renames to finish 2025/05/23 05:29:07 INFO : sub/yam: Moved (server-side) to: yam 2025/05/23 05:29:07 INFO : yam: Renamed from "sub/yam" 2025/05/23 05:29:07 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dusorix4sahe': Waiting for transfers to finish 2025/05/23 05:29:07 DEBUG : Waiting for deletions to finish 2025/05/23 05:29:07 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dusorix4sahe'", Local "Local file system at /tmp/rclone1671050868", Modify Window "1ms" --- PASS: TestSyncWithTrackRenamesStrategyLeaf (8.70s) === RUN TestServerSideMoveLocal run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dusorix4sahe'", Local "Local file system at /tmp/rclone1671050868", Modify Window "1ms" 2025/05/23 05:29:11 DEBUG : Creating backend with remote "/tmp/rclone1671050868/dir1" 2025/05/23 05:29:11 DEBUG : Creating backend with remote "/tmp/rclone1671050868/dir2" 2025/05/23 05:29:11 DEBUG : Local file system at /tmp/rclone1671050868/dir2: Using server-side directory move 2025/05/23 05:29:11 INFO : Local file system at /tmp/rclone1671050868/dir2: Server side directory move failed - fallback to file moves: can't copy directory - destination already exists 2025/05/23 05:29:11 DEBUG : file1.txt: Need to transfer - File not found at Destination 2025/05/23 05:29:11 INFO : file1.txt: Moved (server-side) 2025/05/23 05:29:11 DEBUG : Local file system at /tmp/rclone1671050868/dir2: Waiting for checks to finish 2025/05/23 05:29:11 DEBUG : Local file system at /tmp/rclone1671050868/dir2: Waiting for transfers to finish --- PASS: TestServerSideMoveLocal (0.51s) === RUN TestMoveWithDeleteEmptySrcDirs run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dusorix4sahe'", Local "Local file system at /tmp/rclone1671050868", Modify Window "1ms" 2025/05/23 05:29:12 DEBUG : Added delayed dir = "nested", newDst= 2025/05/23 05:29:12 DEBUG : Added delayed dir = "sub dir", newDst= 2025/05/23 05:29:12 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2025/05/23 05:29:12 DEBUG : Added delayed dir = "nested/sub dir", newDst= 2025/05/23 05:29:12 DEBUG : nested/sub dir/file: Need to transfer - File not found at Destination 2025/05/23 05:29:12 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dusorix4sahe': Waiting for checks to finish 2025/05/23 05:29:12 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dusorix4sahe': Waiting for transfers to finish 2025/05/23 05:29:14 DEBUG : sub dir/hello world: md5 = e5df3474e7df528ae5d8a9c68406fe50 OK 2025/05/23 05:29:14 INFO : sub dir/hello world: Copied (new) 2025/05/23 05:29:14 INFO : sub dir/hello world: Deleted 2025/05/23 05:29:16 DEBUG : nested/sub dir/file: md5 = 0ac3158eb72299ccccf8ac548a6593d9 OK 2025/05/23 05:29:16 INFO : nested/sub dir/file: Copied (new) 2025/05/23 05:29:16 INFO : nested/sub dir/file: Deleted 2025/05/23 05:29:16 INFO : nested/sub dir: Set directory modification time (using DirSetModTime) 2025/05/23 05:29:17 INFO : sub dir: Set directory modification time (using DirSetModTime) 2025/05/23 05:29:17 INFO : nested: Set directory modification time (using DirSetModTime) 2025/05/23 05:29:17 INFO : sub dir: Removing directory 2025/05/23 05:29:17 INFO : nested/sub dir: Removing directory 2025/05/23 05:29:17 INFO : nested: Removing directory 2025/05/23 05:29:17 DEBUG : Local file system at /tmp/rclone1671050868: deleted 3 directories run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dusorix4sahe'", Local "Local file system at /tmp/rclone1671050868", Modify Window "1ms" 2025/05/23 05:29:19 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" 2025/05/23 05:29:20 DEBUG : 37qp6d1gohacv723ij3brofbu8/14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "ftp4kuv8se7tqduu6pmmcvjsmk" 2025/05/23 05:29:21 DEBUG : 37qp6d1gohacv723ij3brofbu8: Rmdir: contains trashed file: "14begaa36ih249fgrnfk6nulg0" --- PASS: TestMoveWithDeleteEmptySrcDirs (10.51s) === RUN TestMoveWithoutDeleteEmptySrcDirs run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dusorix4sahe'", Local "Local file system at /tmp/rclone1671050868", Modify Window "1ms" 2025/05/23 05:29:22 DEBUG : Added delayed dir = "nested", newDst= 2025/05/23 05:29:22 DEBUG : Added delayed dir = "sub dir", newDst= 2025/05/23 05:29:22 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2025/05/23 05:29:22 DEBUG : Added delayed dir = "nested/sub dir", newDst= 2025/05/23 05:29:22 DEBUG : nested/sub dir/file: Need to transfer - File not found at Destination 2025/05/23 05:29:22 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dusorix4sahe': Waiting for checks to finish 2025/05/23 05:29:22 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dusorix4sahe': Waiting for transfers to finish 2025/05/23 05:29:24 DEBUG : sub dir/hello world: md5 = 7d669a209509d6cc1157a800c0ed8fcf OK 2025/05/23 05:29:24 INFO : sub dir/hello world: Copied (new) 2025/05/23 05:29:24 INFO : sub dir/hello world: Deleted 2025/05/23 05:29:26 DEBUG : nested/sub dir/file: md5 = 539821af86998b28ed9d347c4fb40313 OK 2025/05/23 05:29:26 INFO : nested/sub dir/file: Copied (new) 2025/05/23 05:29:26 INFO : nested/sub dir/file: Deleted 2025/05/23 05:29:27 INFO : nested/sub dir: Set directory modification time (using DirSetModTime) 2025/05/23 05:29:27 INFO : sub dir: Set directory modification time (using DirSetModTime) 2025/05/23 05:29:27 INFO : nested: Set directory modification time (using DirSetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dusorix4sahe'", Local "Local file system at /tmp/rclone1671050868", Modify Window "1ms" 2025/05/23 05:29:30 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" 2025/05/23 05:29:30 DEBUG : 37qp6d1gohacv723ij3brofbu8/14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "ftp4kuv8se7tqduu6pmmcvjsmk" 2025/05/23 05:29:31 DEBUG : 37qp6d1gohacv723ij3brofbu8: Rmdir: contains trashed file: "14begaa36ih249fgrnfk6nulg0" --- PASS: TestMoveWithoutDeleteEmptySrcDirs (10.38s) === RUN TestMoveWithIgnoreExisting run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dusorix4sahe'", Local "Local file system at /tmp/rclone1671050868", Modify Window "1ms" 2025/05/23 05:29:32 DEBUG : existing: Need to transfer - File not found at Destination 2025/05/23 05:29:32 DEBUG : existing-b: Need to transfer - File not found at Destination 2025/05/23 05:29:32 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dusorix4sahe': Waiting for checks to finish 2025/05/23 05:29:32 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dusorix4sahe': Waiting for transfers to finish 2025/05/23 05:29:34 DEBUG : existing: md5 = 9aa6016a2cbc6688d2a15a7951022f9f OK 2025/05/23 05:29:34 INFO : existing: Copied (new) 2025/05/23 05:29:34 INFO : existing: Deleted 2025/05/23 05:29:34 DEBUG : existing-b: md5 = a569cb03ec73e1b6ff073311cdb48e9a OK 2025/05/23 05:29:34 INFO : existing-b: Copied (new) 2025/05/23 05:29:34 INFO : existing-b: Deleted 2025/05/23 05:29:34 DEBUG : existing: Destination exists, skipping 2025/05/23 05:29:34 DEBUG : existing: Not removing source file as destination file exists and --ignore-existing is set 2025/05/23 05:29:34 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dusorix4sahe': Waiting for checks to finish 2025/05/23 05:29:34 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dusorix4sahe': Waiting for transfers to finish 2025/05/23 05:29:34 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dusorix4sahe'", Local "Local file system at /tmp/rclone1671050868", Modify Window "1ms" --- PASS: TestMoveWithIgnoreExisting (4.15s) === RUN TestServerSideMove run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dusorix4sahe'", Local "Local file system at /tmp/rclone1671050868", Modify Window "1ms" 2025/05/23 05:29:36 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-qijufog0yixu" 2025/05/23 05:29:36 DEBUG : Creating backend with remote "TestDrive:crypt/qs0h8i8ijf4kifhfb47j13t2qshireiennoa3fgf6refagqv6qog" 2025/05/23 05:29:39 DEBUG : potato2: md5 = ed026b151e32f06b61f3a8e0ad25abd8 OK 2025/05/23 05:29:40 DEBUG : empty space: md5 = 27b70bf8fc4595f9202cfd9922351bb6 OK 2025/05/23 05:29:41 DEBUG : potato3: md5 = 436b00bed340214c33e1a6eef63b641c OK sync_test.go:1705: Server side move (if possible) Encrypted drive 'TestCryptDrive:rclone-test-dusorix4sahe' -> Encrypted drive 'TestCryptDrive:rclone-test-qijufog0yixu' 2025/05/23 05:29:44 DEBUG : empty space: md5 = 1c9c14219312002acb9a5ee11d10e8fd OK 2025/05/23 05:29:45 DEBUG : potato3: md5 = b71d84a74d42ef6cb8fc3f87153ea8fa OK 2025/05/23 05:29:45 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-qijufog0yixu': Using server-side directory move 2025/05/23 05:29:45 INFO : Encrypted drive 'TestCryptDrive:rclone-test-qijufog0yixu': Server side directory move failed - fallback to file moves: can't copy directory - destination already exists 2025/05/23 05:29:46 DEBUG : potato2: Need to transfer - File not found at Destination 2025/05/23 05:29:46 DEBUG : empty space: Size and modification time the same (differ by 0s, within tolerance 1ms) 2025/05/23 05:29:46 DEBUG : empty space: Unchanged skipping 2025/05/23 05:29:46 DEBUG : potato3: Sizes differ (src 68 vs dst 60) 2025/05/23 05:29:46 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-qijufog0yixu': Waiting for checks to finish 2025/05/23 05:29:46 INFO : empty space: Deleted 2025/05/23 05:29:46 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-qijufog0yixu': Waiting for transfers to finish 2025/05/23 05:29:46 INFO : potato3: Deleted 2025/05/23 05:29:46 INFO : potato2: Moved (server-side) 2025/05/23 05:29:47 INFO : potato3: Moved (server-side) 2025/05/23 05:29:47 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-yojibeq7yiyo" 2025/05/23 05:29:47 DEBUG : Creating backend with remote "TestDrive:crypt/hii3cl9e27dq0nnv83ktesluabr89ofrhlq0uins0n4mtrji0cg0" 2025/05/23 05:29:48 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yojibeq7yiyo': Using server-side directory move 2025/05/23 05:29:49 INFO : Encrypted drive 'TestCryptDrive:rclone-test-yojibeq7yiyo': Server side directory move succeeded 2025/05/23 05:29:50 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yojibeq7yiyo': Purge remote 2025/05/23 05:29:50 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-qijufog0yixu': Purge remote 2025/05/23 05:29:50 NOTICE: purge failed: directory not found --- PASS: TestServerSideMove (14.39s) === RUN TestServerSideMoveWithFilter run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dusorix4sahe'", Local "Local file system at /tmp/rclone1671050868", Modify Window "1ms" 2025/05/23 05:29:51 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-raxetuw5maju" 2025/05/23 05:29:51 DEBUG : Creating backend with remote "TestDrive:crypt/8p43njjf1irr95naq2meuj0osk41mlr428dhno02ec9klse276l0" 2025/05/23 05:29:53 DEBUG : potato2: md5 = 576f27248aca7f2132db21e4420c143a OK 2025/05/23 05:29:55 DEBUG : empty space: md5 = 4a2f5d172f55bac7e4693cbe44a6ed05 OK 2025/05/23 05:29:57 DEBUG : potato3: md5 = 9c2445394a3252c07255450bb12f6ef3 OK sync_test.go:1705: Server side move (if possible) Encrypted drive 'TestCryptDrive:rclone-test-dusorix4sahe' -> Encrypted drive 'TestCryptDrive:rclone-test-raxetuw5maju' 2025/05/23 05:29:59 DEBUG : empty space: md5 = debab4d6fd6b4b16d4175498831e2297 OK 2025/05/23 05:30:01 DEBUG : potato3: md5 = b40b87654dea8650d6a8339f33c34c2b OK 2025/05/23 05:30:01 DEBUG : empty space: Excluded (Size Filter) 2025/05/23 05:30:01 DEBUG : empty space: Excluded (Size Filter) 2025/05/23 05:30:01 DEBUG : potato2: Need to transfer - File not found at Destination 2025/05/23 05:30:01 DEBUG : potato3: Sizes differ (src 68 vs dst 60) 2025/05/23 05:30:01 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-raxetuw5maju': Waiting for checks to finish 2025/05/23 05:30:01 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-raxetuw5maju': Waiting for transfers to finish 2025/05/23 05:30:02 INFO : potato3: Deleted 2025/05/23 05:30:02 INFO : potato2: Moved (server-side) 2025/05/23 05:30:02 INFO : potato3: Moved (server-side) 2025/05/23 05:30:03 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-wosilit1loti" 2025/05/23 05:30:03 DEBUG : Creating backend with remote "TestDrive:crypt/u90j8j0lur2fsat1hgfkjf4rem9tjk2pt0pl77qr6sk3u6il8e9g" 2025/05/23 05:30:04 DEBUG : empty space: Excluded (Size Filter) 2025/05/23 05:30:04 DEBUG : potato2: Need to transfer - File not found at Destination 2025/05/23 05:30:04 DEBUG : potato3: Need to transfer - File not found at Destination 2025/05/23 05:30:04 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wosilit1loti': Waiting for checks to finish 2025/05/23 05:30:04 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wosilit1loti': Waiting for transfers to finish 2025/05/23 05:30:05 INFO : potato3: Moved (server-side) 2025/05/23 05:30:06 INFO : potato2: Moved (server-side) 2025/05/23 05:30:06 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wosilit1loti': Purge remote 2025/05/23 05:30:07 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-raxetuw5maju': Purge remote --- PASS: TestServerSideMoveWithFilter (17.23s) === RUN TestServerSideMoveDeleteEmptySourceDirs run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dusorix4sahe'", Local "Local file system at /tmp/rclone1671050868", Modify Window "1ms" 2025/05/23 05:30:08 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-zuholed6juja" 2025/05/23 05:30:08 DEBUG : Creating backend with remote "TestDrive:crypt/9qun1vf9v814fin1s8lgs3oj60v9icdco1cr2qe57nk4t092uo50" 2025/05/23 05:30:10 DEBUG : potato2: md5 = c3205dacb9232bbe6b8e5915f15834c1 OK 2025/05/23 05:30:12 DEBUG : empty space: md5 = 8d374e60478d7e5ae165f1c5cb8485df OK 2025/05/23 05:30:13 DEBUG : potato3: md5 = e650e9878767747b7fba8bc1aa7b9f53 OK 2025/05/23 05:30:13 INFO : tomatoDir: Making directory sync_test.go:1705: Server side move (if possible) Encrypted drive 'TestCryptDrive:rclone-test-dusorix4sahe' -> Encrypted drive 'TestCryptDrive:rclone-test-zuholed6juja' 2025/05/23 05:30:16 DEBUG : empty space: md5 = 7faa3ff662eedd3040cd9d980446a4cf OK 2025/05/23 05:30:18 DEBUG : potato3: md5 = 0ff7de4e3de00cdf794287f03499f249 OK 2025/05/23 05:30:18 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zuholed6juja': Using server-side directory move 2025/05/23 05:30:18 INFO : Encrypted drive 'TestCryptDrive:rclone-test-zuholed6juja': Server side directory move failed - fallback to file moves: can't copy directory - destination already exists 2025/05/23 05:30:18 DEBUG : potato2: Need to transfer - File not found at Destination 2025/05/23 05:30:18 DEBUG : Added delayed dir = "tomatoDir", newDst= 2025/05/23 05:30:18 DEBUG : empty space: Size and modification time the same (differ by 0s, within tolerance 1ms) 2025/05/23 05:30:18 DEBUG : empty space: Unchanged skipping 2025/05/23 05:30:18 DEBUG : potato3: Sizes differ (src 68 vs dst 60) 2025/05/23 05:30:18 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zuholed6juja': Waiting for checks to finish 2025/05/23 05:30:19 INFO : empty space: Deleted 2025/05/23 05:30:19 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zuholed6juja': Waiting for transfers to finish 2025/05/23 05:30:19 INFO : potato3: Deleted 2025/05/23 05:30:19 INFO : potato2: Moved (server-side) 2025/05/23 05:30:19 INFO : potato3: Moved (server-side) 2025/05/23 05:30:19 INFO : tomatoDir: Removing directory 2025/05/23 05:30:20 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dusorix4sahe': deleted 1 directories 2025/05/23 05:30:21 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-hivuqux2noba" 2025/05/23 05:30:21 DEBUG : Creating backend with remote "TestDrive:crypt/t82a3embou8iprjq8psg6cukerkb9k5tkfrjibmgsha2hhcqg9g0" 2025/05/23 05:30:22 INFO : tomatoDir: Making directory 2025/05/23 05:30:22 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hivuqux2noba': Using server-side directory move 2025/05/23 05:30:23 INFO : Encrypted drive 'TestCryptDrive:rclone-test-hivuqux2noba': Server side directory move succeeded 2025/05/23 05:30:24 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hivuqux2noba': Purge remote 2025/05/23 05:30:25 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zuholed6juja': Purge remote 2025/05/23 05:30:25 NOTICE: purge failed: directory not found --- PASS: TestServerSideMoveDeleteEmptySourceDirs (17.42s) === RUN TestServerSideMoveOverlap run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dusorix4sahe'", Local "Local file system at /tmp/rclone1671050868", Modify Window "1ms" sync_test.go:1910: Skipping test as remote supports DirMove --- SKIP: TestServerSideMoveOverlap (0.45s) === RUN TestSyncOverlap run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dusorix4sahe'", Local "Local file system at /tmp/rclone1671050868", Modify Window "1ms" 2025/05/23 05:30:26 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-dusorix4sahe/rclone-sync-test" 2025/05/23 05:30:26 DEBUG : Creating backend with remote "TestDrive:crypt/fii6k2ajsollg3rgnctuvi954tfqhghtln2rjn6esq5lrafat29g/i7355aa0sb89uagn75vfjqr6s3e3e1h2et8in57abn1fe8qfego0" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dusorix4sahe'", Local "Local file system at /tmp/rclone1671050868", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dusorix4sahe'", Local "Local file system at /tmp/rclone1671050868", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dusorix4sahe'", Local "Local file system at /tmp/rclone1671050868", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dusorix4sahe'", Local "Local file system at /tmp/rclone1671050868", Modify Window "1ms" --- PASS: TestSyncOverlap (3.68s) === RUN TestSyncOverlapWithFilter run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dusorix4sahe'", Local "Local file system at /tmp/rclone1671050868", Modify Window "1ms" 2025/05/23 05:30:30 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-dusorix4sahe/rclone-sync-test" 2025/05/23 05:30:30 DEBUG : Creating backend with remote "TestDrive:crypt/fii6k2ajsollg3rgnctuvi954tfqhghtln2rjn6esq5lrafat29g/i7355aa0sb89uagn75vfjqr6s3e3e1h2et8in57abn1fe8qfego0" 2025/05/23 05:30:32 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-dusorix4sahe/rclone-sync-test-include/layer2" 2025/05/23 05:30:32 DEBUG : Creating backend with remote "TestDrive:crypt/fii6k2ajsollg3rgnctuvi954tfqhghtln2rjn6esq5lrafat29g/khf2vlblvnbf9ftevqm0htmss73hj1j5a7q328e4ohrgs7e2loe0/n01jpl9202nn9ec1rb75h0f1c4" 2025/05/23 05:30:35 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-dusorix4sahe/rclone-sync-test-ignore-file" 2025/05/23 05:30:35 DEBUG : Creating backend with remote "TestDrive:crypt/fii6k2ajsollg3rgnctuvi954tfqhghtln2rjn6esq5lrafat29g/kmf11jujl9uha3tjganvgpkn45bu778hb5vb5riug1c26b38k7sg" 2025/05/23 05:30:39 DEBUG : rclone-sync-test-ignore-file/.ignore: md5 = 07b862ef5df70ce5feab5c555125114e OK 2025/05/23 05:30:41 DEBUG : Added delayed dir = "rclone-sync-test-include", newDst= 2025/05/23 05:30:41 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dusorix4sahe/rclone-sync-test': Waiting for checks to finish 2025/05/23 05:30:41 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dusorix4sahe/rclone-sync-test': Waiting for transfers to finish 2025/05/23 05:30:41 DEBUG : Waiting for deletions to finish 2025/05/23 05:30:41 INFO : There was nothing to transfer 2025/05/23 05:30:43 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dusorix4sahe': Waiting for checks to finish 2025/05/23 05:30:43 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dusorix4sahe': Waiting for transfers to finish 2025/05/23 05:30:43 DEBUG : Waiting for deletions to finish 2025/05/23 05:30:43 INFO : rclone-sync-test-include: Removing directory 2025/05/23 05:30:43 DEBUG : khf2vlblvnbf9ftevqm0htmss73hj1j5a7q328e4ohrgs7e2loe0: Rmdir: contains file: "n01jpl9202nn9ec1rb75h0f1c4" 2025/05/23 05:30:43 DEBUG : rclone-sync-test-include: Failed to Rmdir: directory not empty 2025/05/23 05:30:43 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dusorix4sahe': failed to delete 1 directories 2025/05/23 05:30:43 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dusorix4sahe'", Local "Local file system at /tmp/rclone1671050868", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dusorix4sahe'", Local "Local file system at /tmp/rclone1671050868", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dusorix4sahe'", Local "Local file system at /tmp/rclone1671050868", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dusorix4sahe'", Local "Local file system at /tmp/rclone1671050868", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dusorix4sahe'", Local "Local file system at /tmp/rclone1671050868", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dusorix4sahe'", Local "Local file system at /tmp/rclone1671050868", Modify Window "1ms" 2025/05/23 05:30:45 DEBUG : Added delayed dir = "rclone-sync-test-include", newDst= 2025/05/23 05:30:45 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dusorix4sahe/rclone-sync-test-include/layer2': Waiting for checks to finish 2025/05/23 05:30:45 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dusorix4sahe/rclone-sync-test-include/layer2': Waiting for transfers to finish 2025/05/23 05:30:45 DEBUG : Waiting for deletions to finish 2025/05/23 05:30:45 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dusorix4sahe'", Local "Local file system at /tmp/rclone1671050868", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dusorix4sahe'", Local "Local file system at /tmp/rclone1671050868", Modify Window "1ms" 2025/05/23 05:30:47 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dusorix4sahe': Waiting for checks to finish 2025/05/23 05:30:47 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dusorix4sahe': Waiting for transfers to finish 2025/05/23 05:30:47 DEBUG : Waiting for deletions to finish 2025/05/23 05:30:47 INFO : rclone-sync-test-include: Removing directory 2025/05/23 05:30:47 DEBUG : khf2vlblvnbf9ftevqm0htmss73hj1j5a7q328e4ohrgs7e2loe0: Rmdir: contains file: "n01jpl9202nn9ec1rb75h0f1c4" 2025/05/23 05:30:47 DEBUG : rclone-sync-test-include: Failed to Rmdir: directory not empty 2025/05/23 05:30:47 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dusorix4sahe': failed to delete 1 directories 2025/05/23 05:30:47 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dusorix4sahe'", Local "Local file system at /tmp/rclone1671050868", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dusorix4sahe'", Local "Local file system at /tmp/rclone1671050868", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dusorix4sahe'", Local "Local file system at /tmp/rclone1671050868", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dusorix4sahe'", Local "Local file system at /tmp/rclone1671050868", Modify Window "1ms" 2025/05/23 05:30:49 DEBUG : Added delayed dir = "rclone-sync-test-include", newDst= 2025/05/23 05:30:49 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dusorix4sahe/rclone-sync-test-ignore-file': Waiting for checks to finish 2025/05/23 05:30:49 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dusorix4sahe/rclone-sync-test-ignore-file': Waiting for transfers to finish 2025/05/23 05:30:49 DEBUG : Waiting for deletions to finish 2025/05/23 05:30:49 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dusorix4sahe'", Local "Local file system at /tmp/rclone1671050868", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dusorix4sahe'", Local "Local file system at /tmp/rclone1671050868", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dusorix4sahe'", Local "Local file system at /tmp/rclone1671050868", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dusorix4sahe'", Local "Local file system at /tmp/rclone1671050868", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dusorix4sahe'", Local "Local file system at /tmp/rclone1671050868", Modify Window "1ms" 2025/05/23 05:30:51 DEBUG : khf2vlblvnbf9ftevqm0htmss73hj1j5a7q328e4ohrgs7e2loe0: Rmdir: contains trashed file: "n01jpl9202nn9ec1rb75h0f1c4" 2025/05/23 05:30:52 DEBUG : kmf11jujl9uha3tjganvgpkn45bu778hb5vb5riug1c26b38k7sg: Rmdir: contains trashed file: "i0t74httmdlljg425j6tg570d8" --- PASS: TestSyncOverlapWithFilter (31.10s) === RUN TestSyncCompareDest run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dusorix4sahe'", Local "Local file system at /tmp/rclone1671050868", Modify Window "1ms" 2025/05/23 05:31:01 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-dusorix4sahe/dst" 2025/05/23 05:31:01 DEBUG : Creating backend with remote "TestDrive:crypt/fii6k2ajsollg3rgnctuvi954tfqhghtln2rjn6esq5lrafat29g/31u3jie661vd5p8j7rtc3hgbh0" 2025/05/23 05:31:02 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-dusorix4sahe/CompareDest" 2025/05/23 05:31:02 DEBUG : Creating backend with remote "TestDrive:crypt/fii6k2ajsollg3rgnctuvi954tfqhghtln2rjn6esq5lrafat29g/gveqi14airsml4bgu7krj116o8" 2025/05/23 05:31:04 DEBUG : one: Need to transfer - File not found at Destination 2025/05/23 05:31:04 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dusorix4sahe/dst': Waiting for checks to finish 2025/05/23 05:31:04 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dusorix4sahe/dst': Waiting for transfers to finish 2025/05/23 05:31:06 DEBUG : one: md5 = 1b01ff68c9a98fac2a6fef7e898ee122 OK 2025/05/23 05:31:06 INFO : one: Copied (new) 2025/05/23 05:31:06 DEBUG : Waiting for deletions to finish 2025/05/23 05:31:07 DEBUG : one: Sizes differ (src 5 vs dst 3) 2025/05/23 05:31:07 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dusorix4sahe/dst': Waiting for checks to finish 2025/05/23 05:31:08 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dusorix4sahe/dst': Waiting for transfers to finish 2025/05/23 05:31:09 DEBUG : one: md5 = 0887291db86ab8b8d28d66501bb0de57 OK 2025/05/23 05:31:09 INFO : one: Copied (replaced existing) 2025/05/23 05:31:09 DEBUG : Waiting for deletions to finish 2025/05/23 05:31:11 DEBUG : dst/one: md5 = b003d77365372559b8fde3ff14f1f3b7 OK 2025/05/23 05:31:13 DEBUG : CompareDest/one: md5 = 262c2b95b835546c2681fc4a78a4cd77 OK 2025/05/23 05:31:13 DEBUG : one: Sizes differ (src 5 vs dst 3) 2025/05/23 05:31:13 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dusorix4sahe/dst': Waiting for checks to finish 2025/05/23 05:31:14 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/05/23 05:31:14 DEBUG : one: Destination found in --compare-dest, skipping 2025/05/23 05:31:14 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dusorix4sahe/dst': Waiting for transfers to finish 2025/05/23 05:31:14 DEBUG : Waiting for deletions to finish 2025/05/23 05:31:14 INFO : There was nothing to transfer 2025/05/23 05:31:16 DEBUG : CompareDest/two: md5 = e10cd4b998e2347607946b6507c4702d OK 2025/05/23 05:31:16 DEBUG : one: Sizes differ (src 5 vs dst 3) 2025/05/23 05:31:17 DEBUG : two: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/05/23 05:31:17 DEBUG : two: Destination found in --compare-dest, skipping 2025/05/23 05:31:17 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dusorix4sahe/dst': Waiting for checks to finish 2025/05/23 05:31:17 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/05/23 05:31:17 DEBUG : one: Destination found in --compare-dest, skipping 2025/05/23 05:31:17 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dusorix4sahe/dst': Waiting for transfers to finish 2025/05/23 05:31:17 DEBUG : Waiting for deletions to finish 2025/05/23 05:31:17 INFO : There was nothing to transfer 2025/05/23 05:31:17 DEBUG : one: Sizes differ (src 5 vs dst 3) 2025/05/23 05:31:18 DEBUG : two: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/05/23 05:31:18 DEBUG : two: Destination found in --compare-dest, skipping 2025/05/23 05:31:18 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dusorix4sahe/dst': Waiting for checks to finish 2025/05/23 05:31:18 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/05/23 05:31:18 DEBUG : one: Destination found in --compare-dest, skipping 2025/05/23 05:31:18 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dusorix4sahe/dst': Waiting for transfers to finish 2025/05/23 05:31:18 DEBUG : Waiting for deletions to finish 2025/05/23 05:31:18 INFO : There was nothing to transfer sync_test.go:2175: No hash on uploaded file so skipping compare timestamp test 2025/05/23 05:31:19 DEBUG : one: Sizes differ (src 5 vs dst 3) 2025/05/23 05:31:19 DEBUG : two: Sizes differ (src 5 vs dst 3) 2025/05/23 05:31:19 DEBUG : two: Need to transfer - File not found at Destination 2025/05/23 05:31:19 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dusorix4sahe/dst': Waiting for checks to finish 2025/05/23 05:31:19 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/05/23 05:31:19 DEBUG : one: Destination found in --compare-dest, skipping 2025/05/23 05:31:19 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dusorix4sahe/dst': Waiting for transfers to finish 2025/05/23 05:31:21 DEBUG : two: md5 = 133512d39ace65332b9639d15218fbc4 OK 2025/05/23 05:31:21 INFO : two: Copied (new) 2025/05/23 05:31:21 DEBUG : Waiting for deletions to finish 2025/05/23 05:31:24 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k" 2025/05/23 05:31:24 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" 2025/05/23 05:31:24 DEBUG : gveqi14airsml4bgu7krj116o8: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k" 2025/05/23 05:31:24 DEBUG : gveqi14airsml4bgu7krj116o8: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" --- PASS: TestSyncCompareDest (24.40s) === RUN TestSyncMultipleCompareDest run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dusorix4sahe'", Local "Local file system at /tmp/rclone1671050868", Modify Window "1ms" 2025/05/23 05:31:27 DEBUG : pre-dest1/1: md5 = 58aace590e695835ca675ab72ffd33cd OK 2025/05/23 05:31:30 DEBUG : pre-dest2/2: md5 = 40e3403e3a3accbee8ec8605fc57e5ef OK 2025/05/23 05:31:30 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-dusorix4sahe/dest" 2025/05/23 05:31:30 DEBUG : Creating backend with remote "TestDrive:crypt/fii6k2ajsollg3rgnctuvi954tfqhghtln2rjn6esq5lrafat29g/rg03c1jvnehrrc617i0lnqjddc" 2025/05/23 05:31:32 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-dusorix4sahe/pre-dest1" 2025/05/23 05:31:32 DEBUG : Creating backend with remote "TestDrive:crypt/fii6k2ajsollg3rgnctuvi954tfqhghtln2rjn6esq5lrafat29g/bbnblvh6k061ssopqrp18kd7gc" 2025/05/23 05:31:33 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-dusorix4sahe/pre-dest2" 2025/05/23 05:31:33 DEBUG : Creating backend with remote "TestDrive:crypt/fii6k2ajsollg3rgnctuvi954tfqhghtln2rjn6esq5lrafat29g/dgicm1h6b5ejvlltm8eeif0bnk" 2025/05/23 05:31:34 DEBUG : 1: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/05/23 05:31:34 DEBUG : 1: Destination found in --compare-dest, skipping 2025/05/23 05:31:34 DEBUG : 2: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/05/23 05:31:34 DEBUG : 2: Destination found in --compare-dest, skipping 2025/05/23 05:31:35 DEBUG : 3: Need to transfer - File not found at Destination 2025/05/23 05:31:35 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dusorix4sahe/dest': Waiting for checks to finish 2025/05/23 05:31:35 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dusorix4sahe/dest': Waiting for transfers to finish 2025/05/23 05:31:37 DEBUG : 3: md5 = 71236f91a19f23e8beda5db0dd6071e8 OK 2025/05/23 05:31:37 INFO : 3: Copied (new) 2025/05/23 05:31:37 DEBUG : Waiting for deletions to finish 2025/05/23 05:31:40 DEBUG : dgicm1h6b5ejvlltm8eeif0bnk: Rmdir: contains trashed file: "1ghu8geql9vrl726n32nrf65bc" 2025/05/23 05:31:40 DEBUG : bbnblvh6k061ssopqrp18kd7gc: Rmdir: contains trashed file: "skbfko3oil7es0lj68ob574sro" 2025/05/23 05:31:41 DEBUG : rg03c1jvnehrrc617i0lnqjddc: Rmdir: contains trashed file: "g072p7hmjchlnj0gibe64c1epg" --- PASS: TestSyncMultipleCompareDest (16.62s) === RUN TestSyncCopyDest run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dusorix4sahe'", Local "Local file system at /tmp/rclone1671050868", Modify Window "1ms" 2025/05/23 05:31:42 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-dusorix4sahe/dst" 2025/05/23 05:31:42 DEBUG : Creating backend with remote "TestDrive:crypt/fii6k2ajsollg3rgnctuvi954tfqhghtln2rjn6esq5lrafat29g/31u3jie661vd5p8j7rtc3hgbh0" 2025/05/23 05:31:43 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-dusorix4sahe/CopyDest" 2025/05/23 05:31:43 DEBUG : Creating backend with remote "TestDrive:crypt/fii6k2ajsollg3rgnctuvi954tfqhghtln2rjn6esq5lrafat29g/d09o6po3f7bm6ce32vdgs8h9ls" 2025/05/23 05:31:45 DEBUG : one: Need to transfer - File not found at Destination 2025/05/23 05:31:45 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dusorix4sahe/dst': Waiting for checks to finish 2025/05/23 05:31:45 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dusorix4sahe/dst': Waiting for transfers to finish 2025/05/23 05:31:47 DEBUG : one: md5 = 5616c2b35c1f44a71a090226e6de72a8 OK 2025/05/23 05:31:47 INFO : one: Copied (new) 2025/05/23 05:31:47 DEBUG : Waiting for deletions to finish 2025/05/23 05:31:48 DEBUG : one: Sizes differ (src 5 vs dst 3) 2025/05/23 05:31:48 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dusorix4sahe/dst': Waiting for checks to finish 2025/05/23 05:31:49 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dusorix4sahe/dst': Waiting for transfers to finish 2025/05/23 05:31:50 DEBUG : one: md5 = b8143703410d620131ea62d1c8cd8b69 OK 2025/05/23 05:31:50 INFO : one: Copied (replaced existing) 2025/05/23 05:31:50 DEBUG : Waiting for deletions to finish 2025/05/23 05:31:51 DEBUG : dst/one: md5 = d0776e86a2dfbe19c298b2f592c91c47 OK 2025/05/23 05:31:53 DEBUG : CopyDest/one: md5 = 0f702e3ed89f0622609ae63e58cfba7a OK 2025/05/23 05:31:54 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-dusorix4sahe/BackupDir" 2025/05/23 05:31:54 DEBUG : Creating backend with remote "TestDrive:crypt/fii6k2ajsollg3rgnctuvi954tfqhghtln2rjn6esq5lrafat29g/s6dbk3lfi7c9kfvo6j7bla9m0g" 2025/05/23 05:31:56 DEBUG : one: Sizes differ (src 5 vs dst 3) 2025/05/23 05:31:56 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dusorix4sahe/dst': Waiting for checks to finish 2025/05/23 05:31:56 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/05/23 05:31:56 DEBUG : one: Sizes differ (src 5 vs dst 3) 2025/05/23 05:31:57 INFO : one: Moved (server-side) 2025/05/23 05:31:58 INFO : one: Copied (server-side copy) 2025/05/23 05:31:58 DEBUG : one: Destination found in --copy-dest, using server-side copy 2025/05/23 05:31:58 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dusorix4sahe/dst': Waiting for transfers to finish 2025/05/23 05:31:58 DEBUG : Waiting for deletions to finish 2025/05/23 05:32:00 DEBUG : CopyDest/two: md5 = bb0cca2ccc97155c92df33deca083ce0 OK 2025/05/23 05:32:01 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/05/23 05:32:01 DEBUG : one: Unchanged skipping 2025/05/23 05:32:01 DEBUG : two: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/05/23 05:32:02 INFO : two: Copied (server-side copy) 2025/05/23 05:32:02 DEBUG : two: Destination found in --copy-dest, using server-side copy 2025/05/23 05:32:02 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dusorix4sahe/dst': Waiting for checks to finish 2025/05/23 05:32:02 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dusorix4sahe/dst': Waiting for transfers to finish 2025/05/23 05:32:02 DEBUG : Waiting for deletions to finish 2025/05/23 05:32:03 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/05/23 05:32:03 DEBUG : one: Unchanged skipping 2025/05/23 05:32:03 DEBUG : two: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/05/23 05:32:03 DEBUG : two: Unchanged skipping 2025/05/23 05:32:03 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dusorix4sahe/dst': Waiting for checks to finish 2025/05/23 05:32:03 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dusorix4sahe/dst': Waiting for transfers to finish 2025/05/23 05:32:03 DEBUG : Waiting for deletions to finish 2025/05/23 05:32:03 INFO : There was nothing to transfer 2025/05/23 05:32:05 DEBUG : CopyDest/three: md5 = 55ea60d397285fbda67ca88eb7b31e76 OK 2025/05/23 05:32:05 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/05/23 05:32:05 DEBUG : one: Unchanged skipping 2025/05/23 05:32:06 DEBUG : three: Sizes differ (src 7 vs dst 5) 2025/05/23 05:32:06 DEBUG : three: Destination not found in --copy-dest 2025/05/23 05:32:06 DEBUG : three: Need to transfer - File not found at Destination 2025/05/23 05:32:06 DEBUG : two: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/05/23 05:32:06 DEBUG : two: Unchanged skipping 2025/05/23 05:32:06 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dusorix4sahe/dst': Waiting for checks to finish 2025/05/23 05:32:06 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dusorix4sahe/dst': Waiting for transfers to finish 2025/05/23 05:32:07 DEBUG : three: md5 = ab011da3c19b4d8b4cada75551c438b9 OK 2025/05/23 05:32:07 INFO : three: Copied (new) 2025/05/23 05:32:07 DEBUG : Waiting for deletions to finish 2025/05/23 05:32:11 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "b6jdmn2b1adrhc8vikh7edr9os" 2025/05/23 05:32:11 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k" 2025/05/23 05:32:11 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" 2025/05/23 05:32:12 DEBUG : d09o6po3f7bm6ce32vdgs8h9ls: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" 2025/05/23 05:32:12 DEBUG : d09o6po3f7bm6ce32vdgs8h9ls: Rmdir: contains trashed file: "b6jdmn2b1adrhc8vikh7edr9os" 2025/05/23 05:32:12 DEBUG : d09o6po3f7bm6ce32vdgs8h9ls: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k" 2025/05/23 05:32:13 DEBUG : s6dbk3lfi7c9kfvo6j7bla9m0g: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" --- PASS: TestSyncCopyDest (31.67s) === RUN TestSyncBackupDir run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dusorix4sahe'", Local "Local file system at /tmp/rclone1671050868", Modify Window "1ms" 2025/05/23 05:32:15 DEBUG : dst/one: md5 = 45fd67d91725d96d95cd4426d3c3af85 OK 2025/05/23 05:32:17 DEBUG : dst/two: md5 = fb5995470f04ba5d1b279c13fcd593d6 OK 2025/05/23 05:32:18 DEBUG : dst/three.txt: md5 = 7d1306ee6d48b722e67277c412cef645 OK 2025/05/23 05:32:18 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-dusorix4sahe/dst" 2025/05/23 05:32:19 DEBUG : Creating backend with remote "TestDrive:crypt/fii6k2ajsollg3rgnctuvi954tfqhghtln2rjn6esq5lrafat29g/31u3jie661vd5p8j7rtc3hgbh0" 2025/05/23 05:32:19 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-dusorix4sahe/backup" 2025/05/23 05:32:19 DEBUG : Creating backend with remote "TestDrive:crypt/fii6k2ajsollg3rgnctuvi954tfqhghtln2rjn6esq5lrafat29g/1nrff024r7pq65ecp72fc28jb0" 2025/05/23 05:32:21 DEBUG : one: Sizes differ (src 4 vs dst 3) 2025/05/23 05:32:21 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/05/23 05:32:21 DEBUG : two: Unchanged skipping 2025/05/23 05:32:21 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dusorix4sahe/dst': Waiting for checks to finish 2025/05/23 05:32:23 INFO : one: Moved (server-side) 2025/05/23 05:32:23 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dusorix4sahe/dst': Waiting for transfers to finish 2025/05/23 05:32:24 DEBUG : one: md5 = 7d95bf1ad80f5960dd513dccd1951b6c OK 2025/05/23 05:32:24 INFO : one: Copied (new) 2025/05/23 05:32:24 DEBUG : Waiting for deletions to finish 2025/05/23 05:32:25 INFO : three.txt: Moved (server-side) 2025/05/23 05:32:25 INFO : three.txt: Moved into backup dir 2025/05/23 05:32:27 DEBUG : dst/three.txt: md5 = 6ae21e89a9159a45db248b41b01d8246 OK 2025/05/23 05:32:27 DEBUG : one: Sizes differ (src 5 vs dst 4) 2025/05/23 05:32:27 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/05/23 05:32:27 DEBUG : two: Unchanged skipping 2025/05/23 05:32:27 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dusorix4sahe/dst': Waiting for checks to finish 2025/05/23 05:32:28 INFO : one: Deleted 2025/05/23 05:32:29 INFO : one: Moved (server-side) 2025/05/23 05:32:29 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dusorix4sahe/dst': Waiting for transfers to finish 2025/05/23 05:32:30 DEBUG : one: md5 = acb4b79eb377667ff4f831b7e17b3c16 OK 2025/05/23 05:32:30 INFO : one: Copied (new) 2025/05/23 05:32:30 DEBUG : Waiting for deletions to finish 2025/05/23 05:32:31 INFO : three.txt: Deleted 2025/05/23 05:32:31 INFO : three.txt: Moved (server-side) 2025/05/23 05:32:31 INFO : three.txt: Moved into backup dir 2025/05/23 05:32:34 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" 2025/05/23 05:32:34 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k" 2025/05/23 05:32:35 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "tr2hj63d80ftlmvm6a952snjcc" 2025/05/23 05:32:35 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" 2025/05/23 05:32:35 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "tr2hj63d80ftlmvm6a952snjcc" 2025/05/23 05:32:35 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" --- PASS: TestSyncBackupDir (22.02s) === RUN TestSyncBackupDirWithSuffix run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dusorix4sahe'", Local "Local file system at /tmp/rclone1671050868", Modify Window "1ms" 2025/05/23 05:32:38 DEBUG : dst/one: md5 = aa4f237210ef706da085bb9c1ca51b65 OK 2025/05/23 05:32:39 DEBUG : dst/two: md5 = 5b9e0c566dcf2cb908c3a2423076ff09 OK 2025/05/23 05:32:40 DEBUG : dst/three.txt: md5 = 7a4dc9d5b7bd2576cb7239a211886085 OK 2025/05/23 05:32:41 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-dusorix4sahe/dst" 2025/05/23 05:32:41 DEBUG : Creating backend with remote "TestDrive:crypt/fii6k2ajsollg3rgnctuvi954tfqhghtln2rjn6esq5lrafat29g/31u3jie661vd5p8j7rtc3hgbh0" 2025/05/23 05:32:41 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-dusorix4sahe/backup" 2025/05/23 05:32:41 DEBUG : Creating backend with remote "TestDrive:crypt/fii6k2ajsollg3rgnctuvi954tfqhghtln2rjn6esq5lrafat29g/1nrff024r7pq65ecp72fc28jb0" 2025/05/23 05:32:43 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/05/23 05:32:43 DEBUG : two: Unchanged skipping 2025/05/23 05:32:43 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dusorix4sahe/dst': Waiting for checks to finish 2025/05/23 05:32:43 DEBUG : one: Sizes differ (src 4 vs dst 3) 2025/05/23 05:32:44 INFO : one: Moved (server-side) to: one.bak 2025/05/23 05:32:44 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dusorix4sahe/dst': Waiting for transfers to finish 2025/05/23 05:32:46 DEBUG : one: md5 = 6aa7cd652f3020ee5d3209ce2e664305 OK 2025/05/23 05:32:46 INFO : one: Copied (new) 2025/05/23 05:32:46 DEBUG : Waiting for deletions to finish 2025/05/23 05:32:47 INFO : three.txt: Moved (server-side) to: three.txt.bak 2025/05/23 05:32:47 INFO : three.txt: Moved into backup dir 2025/05/23 05:32:48 DEBUG : dst/three.txt: md5 = 8912de038e5d6348eb8c02399122beaa OK 2025/05/23 05:32:49 DEBUG : one: Sizes differ (src 5 vs dst 4) 2025/05/23 05:32:49 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/05/23 05:32:49 DEBUG : two: Unchanged skipping 2025/05/23 05:32:49 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dusorix4sahe/dst': Waiting for checks to finish 2025/05/23 05:32:50 INFO : one.bak: Deleted 2025/05/23 05:32:50 INFO : one: Moved (server-side) to: one.bak 2025/05/23 05:32:50 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dusorix4sahe/dst': Waiting for transfers to finish 2025/05/23 05:32:51 DEBUG : one: md5 = 5526e56bfaecd3df03d9620ccd5b7798 OK 2025/05/23 05:32:51 INFO : one: Copied (new) 2025/05/23 05:32:51 DEBUG : Waiting for deletions to finish 2025/05/23 05:32:52 INFO : three.txt.bak: Deleted 2025/05/23 05:32:53 INFO : three.txt: Moved (server-side) to: three.txt.bak 2025/05/23 05:32:53 INFO : three.txt: Moved into backup dir 2025/05/23 05:32:56 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" 2025/05/23 05:32:56 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k" 2025/05/23 05:32:56 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "qltcak2uaegtmcoa8vijdppbp8" 2025/05/23 05:32:56 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "sk91qgsqfn0r271r2ehsaoc20c" 2025/05/23 05:32:56 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "sk91qgsqfn0r271r2ehsaoc20c" 2025/05/23 05:32:56 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "qltcak2uaegtmcoa8vijdppbp8" --- PASS: TestSyncBackupDirWithSuffix (21.53s) === RUN TestSyncBackupDirWithSuffixKeepExtension run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dusorix4sahe'", Local "Local file system at /tmp/rclone1671050868", Modify Window "1ms" 2025/05/23 05:32:59 DEBUG : dst/one: md5 = 7ab456ceaea09c91423b20f9c555fd70 OK 2025/05/23 05:33:00 DEBUG : dst/two: md5 = 6229a7384ecb0ad4d38b45cfc5e63b37 OK 2025/05/23 05:33:02 DEBUG : dst/three.txt: md5 = fcb3c2a3b6b17640e4dd91244b37fafa OK 2025/05/23 05:33:02 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-dusorix4sahe/dst" 2025/05/23 05:33:02 DEBUG : Creating backend with remote "TestDrive:crypt/fii6k2ajsollg3rgnctuvi954tfqhghtln2rjn6esq5lrafat29g/31u3jie661vd5p8j7rtc3hgbh0" 2025/05/23 05:33:03 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-dusorix4sahe/backup" 2025/05/23 05:33:03 DEBUG : Creating backend with remote "TestDrive:crypt/fii6k2ajsollg3rgnctuvi954tfqhghtln2rjn6esq5lrafat29g/1nrff024r7pq65ecp72fc28jb0" 2025/05/23 05:33:05 DEBUG : one: Sizes differ (src 4 vs dst 3) 2025/05/23 05:33:05 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/05/23 05:33:05 DEBUG : two: Unchanged skipping 2025/05/23 05:33:05 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dusorix4sahe/dst': Waiting for checks to finish 2025/05/23 05:33:06 INFO : one: Moved (server-side) to: one-2019-01-01 2025/05/23 05:33:06 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dusorix4sahe/dst': Waiting for transfers to finish 2025/05/23 05:33:07 DEBUG : one: md5 = 03fdf4db42660615b46383322f1b7777 OK 2025/05/23 05:33:07 INFO : one: Copied (new) 2025/05/23 05:33:07 DEBUG : Waiting for deletions to finish 2025/05/23 05:33:08 INFO : three.txt: Moved (server-side) to: three-2019-01-01.txt 2025/05/23 05:33:08 INFO : three.txt: Moved into backup dir 2025/05/23 05:33:10 DEBUG : dst/three.txt: md5 = 87d459dafbc5d923ed1418c1d463903c OK 2025/05/23 05:33:11 DEBUG : one: Sizes differ (src 5 vs dst 4) 2025/05/23 05:33:11 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/05/23 05:33:11 DEBUG : two: Unchanged skipping 2025/05/23 05:33:11 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dusorix4sahe/dst': Waiting for checks to finish 2025/05/23 05:33:11 INFO : one-2019-01-01: Deleted 2025/05/23 05:33:12 INFO : one: Moved (server-side) to: one-2019-01-01 2025/05/23 05:33:12 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dusorix4sahe/dst': Waiting for transfers to finish 2025/05/23 05:33:13 DEBUG : one: md5 = fc6b5de81d72dba6f80abf85a41ac5b8 OK 2025/05/23 05:33:13 INFO : one: Copied (new) 2025/05/23 05:33:13 DEBUG : Waiting for deletions to finish 2025/05/23 05:33:14 INFO : three-2019-01-01.txt: Deleted 2025/05/23 05:33:14 INFO : three.txt: Moved (server-side) to: three-2019-01-01.txt 2025/05/23 05:33:14 INFO : three.txt: Moved into backup dir 2025/05/23 05:33:17 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" 2025/05/23 05:33:17 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k" 2025/05/23 05:33:18 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "jcjl1bv3ep0v8kt35lqql1co90" 2025/05/23 05:33:18 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "qtq2f6qq4lgpsmj88vb7147qje3prudmtfdtr2342fth58vo9a50" 2025/05/23 05:33:18 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "jcjl1bv3ep0v8kt35lqql1co90" 2025/05/23 05:33:18 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "qtq2f6qq4lgpsmj88vb7147qje3prudmtfdtr2342fth58vo9a50" --- PASS: TestSyncBackupDirWithSuffixKeepExtension (21.81s) === RUN TestSyncBackupDirSuffixOnly run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dusorix4sahe'", Local "Local file system at /tmp/rclone1671050868", Modify Window "1ms" 2025/05/23 05:33:21 DEBUG : dst/one: md5 = 295d5c09f8fd4a5cdb124e991e729987 OK 2025/05/23 05:33:22 DEBUG : dst/two: md5 = c4bb87be807329801a4f2d9c1978bbd0 OK 2025/05/23 05:33:23 DEBUG : dst/three.txt: md5 = 2663e3af76fcb0c6f4df3fe2706a87fc OK 2025/05/23 05:33:24 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-dusorix4sahe/dst" 2025/05/23 05:33:24 DEBUG : Creating backend with remote "TestDrive:crypt/fii6k2ajsollg3rgnctuvi954tfqhghtln2rjn6esq5lrafat29g/31u3jie661vd5p8j7rtc3hgbh0" 2025/05/23 05:33:25 DEBUG : one: Sizes differ (src 4 vs dst 3) 2025/05/23 05:33:25 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/05/23 05:33:25 DEBUG : two: Unchanged skipping 2025/05/23 05:33:25 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dusorix4sahe/dst': Waiting for checks to finish 2025/05/23 05:33:26 INFO : one: Moved (server-side) to: one.bak 2025/05/23 05:33:26 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dusorix4sahe/dst': Waiting for transfers to finish 2025/05/23 05:33:27 DEBUG : one: md5 = 55ec51077c7af42aeaf621462584d93b OK 2025/05/23 05:33:27 INFO : one: Copied (new) 2025/05/23 05:33:27 DEBUG : Waiting for deletions to finish 2025/05/23 05:33:28 INFO : three.txt: Moved (server-side) to: three.txt.bak 2025/05/23 05:33:28 INFO : three.txt: Moved into backup dir 2025/05/23 05:33:29 DEBUG : dst/three.txt: md5 = c0441845930cb7e3f3393c9260ca1436 OK 2025/05/23 05:33:30 DEBUG : three.txt.bak: Excluded (Path Filter) 2025/05/23 05:33:30 DEBUG : one.bak: Excluded (Path Filter) 2025/05/23 05:33:30 DEBUG : one: Sizes differ (src 5 vs dst 4) 2025/05/23 05:33:30 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/05/23 05:33:30 DEBUG : two: Unchanged skipping 2025/05/23 05:33:30 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dusorix4sahe/dst': Waiting for checks to finish 2025/05/23 05:33:31 INFO : one.bak: Deleted 2025/05/23 05:33:31 INFO : one: Moved (server-side) to: one.bak 2025/05/23 05:33:31 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dusorix4sahe/dst': Waiting for transfers to finish 2025/05/23 05:33:33 DEBUG : one: md5 = 0c94802fc848c61387a461fdc115d9f5 OK 2025/05/23 05:33:33 INFO : one: Copied (new) 2025/05/23 05:33:33 DEBUG : Waiting for deletions to finish 2025/05/23 05:33:33 INFO : three.txt.bak: Deleted 2025/05/23 05:33:34 INFO : three.txt: Moved (server-side) to: three.txt.bak 2025/05/23 05:33:34 INFO : three.txt: Moved into backup dir 2025/05/23 05:33:37 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" 2025/05/23 05:33:37 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "sk91qgsqfn0r271r2ehsaoc20c" 2025/05/23 05:33:37 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "qltcak2uaegtmcoa8vijdppbp8" 2025/05/23 05:33:37 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "sk91qgsqfn0r271r2ehsaoc20c" 2025/05/23 05:33:37 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "qltcak2uaegtmcoa8vijdppbp8" 2025/05/23 05:33:37 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k" --- PASS: TestSyncBackupDirSuffixOnly (18.76s) === RUN TestSyncSuffix run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dusorix4sahe'", Local "Local file system at /tmp/rclone1671050868", Modify Window "1ms" 2025/05/23 05:33:39 DEBUG : dst/one: md5 = 96eec5c7d9e4af5c24971656ced6ad74 OK 2025/05/23 05:33:41 DEBUG : dst/two: md5 = a39206f6c5d448fcd2689d33b11db582 OK 2025/05/23 05:33:42 DEBUG : dst/three.txt: md5 = d6a7b77eec402653f51c30d685fe3a74 OK 2025/05/23 05:33:43 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-dusorix4sahe/dst" 2025/05/23 05:33:43 DEBUG : Creating backend with remote "TestDrive:crypt/fii6k2ajsollg3rgnctuvi954tfqhghtln2rjn6esq5lrafat29g/31u3jie661vd5p8j7rtc3hgbh0" 2025/05/23 05:33:44 DEBUG : one: Sizes differ (src 4 vs dst 3) 2025/05/23 05:33:44 INFO : one: Moved (server-side) to: one.bak 2025/05/23 05:33:46 DEBUG : one: md5 = d19a9b7dec3b1495eb296032d534bcdf OK 2025/05/23 05:33:46 INFO : one: Copied (new) 2025/05/23 05:33:46 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/05/23 05:33:46 DEBUG : two: Unchanged skipping 2025/05/23 05:33:46 DEBUG : three.txt: Sizes differ (src 6 vs dst 5) 2025/05/23 05:33:47 INFO : three.txt: Moved (server-side) to: three.txt.bak 2025/05/23 05:33:48 DEBUG : three.txt: md5 = 79137aabf33533e9dd19fcd840c0fe1d OK 2025/05/23 05:33:48 INFO : three.txt: Copied (new) 2025/05/23 05:33:50 DEBUG : one: Sizes differ (src 5 vs dst 4) 2025/05/23 05:33:50 INFO : one.bak: Deleted 2025/05/23 05:33:51 INFO : one: Moved (server-side) to: one.bak 2025/05/23 05:33:52 DEBUG : one: md5 = 89aa76ffea79bf860690af9218a55a46 OK 2025/05/23 05:33:52 INFO : one: Copied (new) 2025/05/23 05:33:52 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/05/23 05:33:52 DEBUG : two: Unchanged skipping 2025/05/23 05:33:52 DEBUG : three.txt: Sizes differ (src 19 vs dst 6) 2025/05/23 05:33:53 INFO : three.txt.bak: Deleted 2025/05/23 05:33:54 INFO : three.txt: Moved (server-side) to: three.txt.bak 2025/05/23 05:33:55 DEBUG : three.txt: md5 = 0344dd2aebb838d1ec5d30e4c8dc3961 OK 2025/05/23 05:33:55 INFO : three.txt: Copied (new) 2025/05/23 05:33:59 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "tr2hj63d80ftlmvm6a952snjcc" 2025/05/23 05:33:59 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" 2025/05/23 05:33:59 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "qltcak2uaegtmcoa8vijdppbp8" 2025/05/23 05:33:59 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "sk91qgsqfn0r271r2ehsaoc20c" 2025/05/23 05:33:59 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "sk91qgsqfn0r271r2ehsaoc20c" 2025/05/23 05:33:59 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "qltcak2uaegtmcoa8vijdppbp8" 2025/05/23 05:33:59 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k" --- PASS: TestSyncSuffix (21.69s) === RUN TestSyncSuffixKeepExtension run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dusorix4sahe'", Local "Local file system at /tmp/rclone1671050868", Modify Window "1ms" 2025/05/23 05:34:01 DEBUG : dst/one: md5 = b9dd0f9213312ecf415e6711064e166d OK 2025/05/23 05:34:03 DEBUG : dst/two: md5 = 4b6adfe68af1ffe1d9d5e4444f1595e2 OK 2025/05/23 05:34:04 DEBUG : dst/three.txt: md5 = fd931e430bed86e865c644429c86cb33 OK 2025/05/23 05:34:05 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-dusorix4sahe/dst" 2025/05/23 05:34:05 DEBUG : Creating backend with remote "TestDrive:crypt/fii6k2ajsollg3rgnctuvi954tfqhghtln2rjn6esq5lrafat29g/31u3jie661vd5p8j7rtc3hgbh0" 2025/05/23 05:34:05 DEBUG : one: Sizes differ (src 4 vs dst 3) 2025/05/23 05:34:06 INFO : one: Moved (server-side) to: one-2019-01-01 2025/05/23 05:34:07 DEBUG : one: md5 = 0eae2a492c2131e44417834d6d44eeda OK 2025/05/23 05:34:07 INFO : one: Copied (new) 2025/05/23 05:34:08 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/05/23 05:34:08 DEBUG : two: Unchanged skipping 2025/05/23 05:34:08 DEBUG : three.txt: Sizes differ (src 6 vs dst 5) 2025/05/23 05:34:09 INFO : three.txt: Moved (server-side) to: three-2019-01-01.txt 2025/05/23 05:34:10 DEBUG : three.txt: md5 = 6edac7663346dd500259db74d0c6d196 OK 2025/05/23 05:34:10 INFO : three.txt: Copied (new) 2025/05/23 05:34:11 DEBUG : one: Sizes differ (src 5 vs dst 4) 2025/05/23 05:34:12 INFO : one-2019-01-01: Deleted 2025/05/23 05:34:13 INFO : one: Moved (server-side) to: one-2019-01-01 2025/05/23 05:34:14 DEBUG : one: md5 = 2de649970f78e8e70e449f84a53367fd OK 2025/05/23 05:34:14 INFO : one: Copied (new) 2025/05/23 05:34:14 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/05/23 05:34:14 DEBUG : two: Unchanged skipping 2025/05/23 05:34:14 DEBUG : three.txt: Sizes differ (src 19 vs dst 6) 2025/05/23 05:34:15 INFO : three-2019-01-01.txt: Deleted 2025/05/23 05:34:16 INFO : three.txt: Moved (server-side) to: three-2019-01-01.txt 2025/05/23 05:34:17 DEBUG : three.txt: md5 = 1aef47ab7c6c55658080db30cad5863a OK 2025/05/23 05:34:17 INFO : three.txt: Copied (new) 2025/05/23 05:34:20 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" 2025/05/23 05:34:20 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "tr2hj63d80ftlmvm6a952snjcc" 2025/05/23 05:34:20 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "jcjl1bv3ep0v8kt35lqql1co90" 2025/05/23 05:34:20 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k" 2025/05/23 05:34:20 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "qtq2f6qq4lgpsmj88vb7147qje3prudmtfdtr2342fth58vo9a50" 2025/05/23 05:34:20 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "qtq2f6qq4lgpsmj88vb7147qje3prudmtfdtr2342fth58vo9a50" 2025/05/23 05:34:20 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "jcjl1bv3ep0v8kt35lqql1co90" --- PASS: TestSyncSuffixKeepExtension (21.92s) === RUN TestSyncUTFNorm run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dusorix4sahe'", Local "Local file system at /tmp/rclone1671050868", Modify Window "1ms" 2025/05/23 05:34:22 DEBUG : Testêé: md5 = 61aa739b71acc402bb71abe4c51f30f2 OK 2025/05/23 05:34:23 DEBUG : Testêé: Sizes differ (src 14 vs dst 18) 2025/05/23 05:34:23 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dusorix4sahe': Waiting for checks to finish 2025/05/23 05:34:23 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dusorix4sahe': Waiting for transfers to finish 2025/05/23 05:34:24 DEBUG : Testêé: md5 = 406d416c5a5a75f92e75c803020da2cd OK 2025/05/23 05:34:24 INFO : Testêé: Copied (replaced existing) to: Testêé 2025/05/23 05:34:24 DEBUG : Waiting for deletions to finish --- PASS: TestSyncUTFNorm (3.95s) === RUN TestSyncImmutable run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dusorix4sahe'", Local "Local file system at /tmp/rclone1671050868", Modify Window "1ms" 2025/05/23 05:34:25 DEBUG : existing: Need to transfer - File not found at Destination 2025/05/23 05:34:25 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dusorix4sahe': Waiting for checks to finish 2025/05/23 05:34:25 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dusorix4sahe': Waiting for transfers to finish 2025/05/23 05:34:27 DEBUG : existing: md5 = 63194333e6a78b7528b83830d6f0d974 OK 2025/05/23 05:34:27 INFO : existing: Copied (new) 2025/05/23 05:34:27 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dusorix4sahe'", Local "Local file system at /tmp/rclone1671050868", Modify Window "1ms" 2025/05/23 05:34:27 DEBUG : existing: Sizes differ (src 8 vs dst 6) 2025/05/23 05:34:27 ERROR : existing: Source and destination exist but do not match: immutable file modified 2025/05/23 05:34:27 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dusorix4sahe': Waiting for checks to finish 2025/05/23 05:34:27 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dusorix4sahe': Waiting for transfers to finish 2025/05/23 05:34:27 ERROR : Encrypted drive 'TestCryptDrive:rclone-test-dusorix4sahe': not deleting files as there were IO errors 2025/05/23 05:34:27 ERROR : Encrypted drive 'TestCryptDrive:rclone-test-dusorix4sahe': not deleting directories as there were IO errors run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dusorix4sahe'", Local "Local file system at /tmp/rclone1671050868", Modify Window "1ms" --- PASS: TestSyncImmutable (4.38s) === RUN TestSyncIgnoreCase run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dusorix4sahe'", Local "Local file system at /tmp/rclone1671050868", Modify Window "1ms" 2025/05/23 05:34:31 DEBUG : EXISTING: md5 = 995f6bae679740abdc85f422eaf94853 OK 2025/05/23 05:34:31 DEBUG : existing: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/05/23 05:34:31 DEBUG : existing: Unchanged skipping 2025/05/23 05:34:31 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dusorix4sahe': Waiting for checks to finish 2025/05/23 05:34:31 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dusorix4sahe': Waiting for transfers to finish 2025/05/23 05:34:31 DEBUG : Waiting for deletions to finish 2025/05/23 05:34:31 INFO : There was nothing to transfer --- PASS: TestSyncIgnoreCase (3.06s) === RUN TestFixCase run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dusorix4sahe'", Local "Local file system at /tmp/rclone1671050868", Modify Window "1ms" sync_test.go:2635: Skipping test as local or remote are case-sensitive --- SKIP: TestFixCase (0.47s) === RUN TestMaxTransfer === RUN TestMaxTransfer/Hard run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dusorix4sahe'", Local "Local file system at /tmp/rclone1671050868", 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-dusorix4sahe'", Local "Local file system at /tmp/rclone1671050868", 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-dusorix4sahe'", Local "Local file system at /tmp/rclone1671050868", Modify Window "1ms" sync_test.go:2674: This test only runs on local --- PASS: TestMaxTransfer (1.34s) --- SKIP: TestMaxTransfer/Hard (0.43s) --- SKIP: TestMaxTransfer/Soft (0.47s) --- SKIP: TestMaxTransfer/Cautious (0.44s) === RUN TestSyncConcurrentDelete run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dusorix4sahe'", Local "Local file system at /tmp/rclone1671050868", Modify Window "1ms" 2025/05/23 05:34:36 DEBUG : both0: md5 = 8719f8f77ee3b9f8dee6d691865234cd OK 2025/05/23 05:34:37 DEBUG : only0: md5 = f88064d50a43461e58107a783d75e865 OK 2025/05/23 05:34:39 DEBUG : both1: md5 = febb63cdf5f0047b013ba91f5e8ea968 OK 2025/05/23 05:34:40 DEBUG : only1: md5 = 1c1debdfaf14be2c79bdd5a38fa5acb8 OK 2025/05/23 05:34:41 DEBUG : both2: md5 = 3e9ab9fe12e367facdf63a9134911160 OK 2025/05/23 05:34:42 DEBUG : only2: md5 = 152de309224f93103b0ab6c3a2580ab6 OK 2025/05/23 05:34:44 DEBUG : both3: md5 = e1a17f10aff5ab6b09502293d248a309 OK 2025/05/23 05:34:45 DEBUG : only3: md5 = 44201007753df214f82985cd38718c4e OK 2025/05/23 05:34:47 DEBUG : both4: md5 = c1575456f42af9c1b6ebc0ac576e53cb OK 2025/05/23 05:34:48 DEBUG : only4: md5 = 29e2af52d32b5b7c96d965b5466bb286 OK 2025/05/23 05:34:49 DEBUG : both5: md5 = f0c02373e6887723f635a7a5bf85ad57 OK 2025/05/23 05:34:51 DEBUG : only5: md5 = 7868bba1cfca9a7b165ef4b10f60638b OK 2025/05/23 05:34:52 DEBUG : both6: md5 = 1d1beddadbbb4024e66a8eb904dac8e6 OK 2025/05/23 05:34:53 DEBUG : only6: md5 = 4dad7286940cb75720111e4203b5c19c OK 2025/05/23 05:34:55 DEBUG : both7: md5 = 8396ed3bd88fb17e3811ab52d81068a9 OK 2025/05/23 05:34:56 DEBUG : only7: md5 = fcb21f35b0a5cab8b75078e8a99c4ca2 OK 2025/05/23 05:34:57 DEBUG : both8: md5 = f4f36642e9b2a253c52a5647e89d4837 OK 2025/05/23 05:34:59 DEBUG : only8: md5 = a3af000c3f5b1eac94f01f137f2f9606 OK 2025/05/23 05:35:00 DEBUG : both9: md5 = 82e51970baecde6a3d733f861c23aacf OK 2025/05/23 05:35:02 DEBUG : only9: md5 = 06c4a7d5c6eb971b70b7cdd8e8270890 OK 2025/05/23 05:35:03 DEBUG : both10: md5 = 33a1b7056f49ed3c8691f563e9f3b81b OK 2025/05/23 05:35:04 DEBUG : only10: md5 = 087bc7203313febd939950f2582cac22 OK 2025/05/23 05:35:06 DEBUG : both11: md5 = 214da41dc71b27fe90da2834a49fcaa0 OK 2025/05/23 05:35:07 DEBUG : only11: md5 = 089eaa39b61dfdc7a9c23ae182a8a089 OK 2025/05/23 05:35:08 DEBUG : both12: md5 = cda50ee397cf523291154c7ae6d308a5 OK 2025/05/23 05:35:09 DEBUG : only12: md5 = 7f8a29d0d85fb4d94c55fde83294d9a8 OK 2025/05/23 05:35:11 DEBUG : both13: md5 = a022024e7f43430d81792bc6499a6a8e OK 2025/05/23 05:35:12 DEBUG : only13: md5 = c0efcf37d86061c90771bdeaf3bbd0e4 OK 2025/05/23 05:35:14 DEBUG : both14: md5 = 0b62daee955ff815b532848218399122 OK 2025/05/23 05:35:15 DEBUG : only14: md5 = cd6b1c39af464d69a6104ad9b216dcc1 OK 2025/05/23 05:35:17 DEBUG : both15: md5 = 25c105426f1e82c30159d6c6d033f1f1 OK 2025/05/23 05:35:18 DEBUG : only15: md5 = 50732d1e188e1279874643ae8ded5754 OK 2025/05/23 05:35:19 DEBUG : both16: md5 = 02d5adf3c8b630741479641f865a5da6 OK 2025/05/23 05:35:21 DEBUG : only16: md5 = 6cdd85250f6a98d1ca6fe855a874a8ce OK 2025/05/23 05:35:22 DEBUG : both17: md5 = f60f48c4aadd5179e698121644e6b0e8 OK 2025/05/23 05:35:24 DEBUG : only17: md5 = 63bc8a5109860b26515af14f6915de5f OK 2025/05/23 05:35:25 DEBUG : both18: md5 = 8ffbf79469eb5e09bf75b5e0919aaee3 OK 2025/05/23 05:35:27 DEBUG : only18: md5 = 3766fd82094ea3ada8a178651f259e24 OK 2025/05/23 05:35:28 DEBUG : both19: md5 = 959e6abbda9c57f66562492555981999 OK 2025/05/23 05:35:29 DEBUG : only19: md5 = 8bc86fc5f75db5e1ac5a7e6c668737ad OK 2025/05/23 05:35:30 DEBUG : both0: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/05/23 05:35:30 DEBUG : both0: Unchanged skipping 2025/05/23 05:35:30 DEBUG : both1: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/05/23 05:35:30 DEBUG : both1: Unchanged skipping 2025/05/23 05:35:30 DEBUG : both10: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/05/23 05:35:30 DEBUG : both10: Unchanged skipping 2025/05/23 05:35:30 DEBUG : both11: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/05/23 05:35:30 DEBUG : both11: Unchanged skipping 2025/05/23 05:35:30 DEBUG : both12: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/05/23 05:35:30 DEBUG : both12: Unchanged skipping 2025/05/23 05:35:30 DEBUG : both13: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/05/23 05:35:30 DEBUG : both13: Unchanged skipping 2025/05/23 05:35:30 DEBUG : both14: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/05/23 05:35:30 DEBUG : both14: Unchanged skipping 2025/05/23 05:35:30 DEBUG : both15: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/05/23 05:35:30 DEBUG : both15: Unchanged skipping 2025/05/23 05:35:30 DEBUG : both16: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/05/23 05:35:30 DEBUG : both16: Unchanged skipping 2025/05/23 05:35:30 DEBUG : both17: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/05/23 05:35:30 DEBUG : both17: Unchanged skipping 2025/05/23 05:35:30 DEBUG : both18: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/05/23 05:35:30 DEBUG : both18: Unchanged skipping 2025/05/23 05:35:30 DEBUG : both19: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/05/23 05:35:30 DEBUG : both19: Unchanged skipping 2025/05/23 05:35:30 DEBUG : both2: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/05/23 05:35:30 DEBUG : both2: Unchanged skipping 2025/05/23 05:35:30 DEBUG : both3: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/05/23 05:35:30 DEBUG : both3: Unchanged skipping 2025/05/23 05:35:30 DEBUG : both4: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/05/23 05:35:30 DEBUG : both4: Unchanged skipping 2025/05/23 05:35:30 DEBUG : both5: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/05/23 05:35:30 DEBUG : both5: Unchanged skipping 2025/05/23 05:35:30 DEBUG : both6: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/05/23 05:35:30 DEBUG : both6: Unchanged skipping 2025/05/23 05:35:30 DEBUG : both7: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/05/23 05:35:30 DEBUG : both7: Unchanged skipping 2025/05/23 05:35:30 DEBUG : both8: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/05/23 05:35:30 DEBUG : both8: Unchanged skipping 2025/05/23 05:35:30 DEBUG : both9: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/05/23 05:35:30 DEBUG : both9: Unchanged skipping 2025/05/23 05:35:30 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dusorix4sahe': Waiting for checks to finish 2025/05/23 05:35:30 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dusorix4sahe': Waiting for transfers to finish 2025/05/23 05:35:30 DEBUG : Waiting for deletions to finish 2025/05/23 05:35:30 INFO : only14: Deleted 2025/05/23 05:35:30 INFO : only18: Deleted 2025/05/23 05:35:30 INFO : only19: Deleted 2025/05/23 05:35:30 INFO : only15: Deleted 2025/05/23 05:35:31 INFO : only9: Deleted 2025/05/23 05:35:31 INFO : only11: Deleted 2025/05/23 05:35:31 INFO : only12: Deleted 2025/05/23 05:35:31 INFO : only16: Deleted 2025/05/23 05:35:31 INFO : only6: Deleted 2025/05/23 05:35:31 INFO : only7: Deleted 2025/05/23 05:35:31 INFO : only3: Deleted 2025/05/23 05:35:31 INFO : only1: Deleted 2025/05/23 05:35:31 INFO : only8: Deleted 2025/05/23 05:35:32 INFO : only10: Deleted 2025/05/23 05:35:32 INFO : only17: Deleted 2025/05/23 05:35:32 INFO : only13: Deleted 2025/05/23 05:35:32 INFO : only2: Deleted 2025/05/23 05:35:32 INFO : only0: Deleted 2025/05/23 05:35:32 INFO : only5: Deleted 2025/05/23 05:35:32 INFO : only4: Deleted 2025/05/23 05:35:32 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dusorix4sahe'", Local "Local file system at /tmp/rclone1671050868", Modify Window "1ms" --- PASS: TestSyncConcurrentDelete (67.51s) === RUN TestSyncConcurrentTruncate run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dusorix4sahe'", Local "Local file system at /tmp/rclone1671050868", Modify Window "1ms" 2025/05/23 05:35:43 DEBUG : both0: md5 = 17fe63b4e1e4c0478a5c9297dd71c746 OK 2025/05/23 05:35:44 DEBUG : only0: md5 = 816bd1edf9b9ecdd623b867620396d0d OK 2025/05/23 05:35:46 DEBUG : both1: md5 = 4e141021fce07399d6fc4867c7b38212 OK 2025/05/23 05:35:48 DEBUG : only1: md5 = 9d32cd944f74d564360c2901aa4270b2 OK 2025/05/23 05:35:49 DEBUG : both2: md5 = eefe50db7ad9d328c8649dde48d6fbac OK 2025/05/23 05:35:50 DEBUG : only2: md5 = c069255b74a2cfa2531ce8abc6a667d8 OK 2025/05/23 05:35:52 DEBUG : both3: md5 = 12885bd0c4d91a853e8cf44da80508a5 OK 2025/05/23 05:35:53 DEBUG : only3: md5 = e27d147caf03bd8d1376c63ac22fe897 OK 2025/05/23 05:35:54 DEBUG : both4: md5 = 7ccf884cd3a2ffe681399e5a33d1cc08 OK 2025/05/23 05:35:56 DEBUG : only4: md5 = 2115b4349b1fae37dd6dc49ab3f03fbb OK 2025/05/23 05:35:57 DEBUG : both5: md5 = e7bddc683648891a58dd49877d4147fd OK 2025/05/23 05:35:58 DEBUG : only5: md5 = fcd6a6659ee65dfc8c2b919c98af71e9 OK 2025/05/23 05:36:00 DEBUG : both6: md5 = 0974b9fc9eeb55ee18ec9c01e19ca548 OK 2025/05/23 05:36:01 DEBUG : only6: md5 = 92a9e9ce940df7e86208eb1034e8d75d OK 2025/05/23 05:36:02 DEBUG : both7: md5 = 8d4bcfc410dc8da8c41b7804a1ff9f9c OK 2025/05/23 05:36:04 DEBUG : only7: md5 = a9f9d625eb3905bcc599fb253257d62e OK 2025/05/23 05:36:05 DEBUG : both8: md5 = 20af7c867b81a31e619cb904d826bf8d OK 2025/05/23 05:36:06 DEBUG : only8: md5 = d3e480a797587c353ea029e07258fa75 OK 2025/05/23 05:36:07 DEBUG : both9: md5 = 81e14a8e7c7401db0edd69b9d9f75473 OK 2025/05/23 05:36:09 DEBUG : only9: md5 = f622af331e357d75b6d9867b12880776 OK 2025/05/23 05:36:10 DEBUG : both10: md5 = 2a89750d9bf80f04367a1f7422e09fea OK 2025/05/23 05:36:11 DEBUG : only10: md5 = 4df1b8d29bc10ab74b891edf451091a8 OK 2025/05/23 05:36:13 DEBUG : both11: md5 = b99ece006012b8e2e64ad11af5bfb004 OK 2025/05/23 05:36:14 DEBUG : only11: md5 = 2ca8f781702a1b9d7cb4af14ac7b5335 OK 2025/05/23 05:36:15 DEBUG : both12: md5 = f80f4611f7dd634222a2e085d92d68c6 OK 2025/05/23 05:36:17 DEBUG : only12: md5 = 97e9f81e6606d668c3491d12b0c1463b OK 2025/05/23 05:36:18 DEBUG : both13: md5 = 0b677712b65d22f489c91e7680b3a8f6 OK 2025/05/23 05:36:20 DEBUG : only13: md5 = 5d7f32e8204b0cfc9ed0022f7c4f6cc5 OK 2025/05/23 05:36:21 DEBUG : both14: md5 = 6e565e6641994e77b9aec526b3efe027 OK 2025/05/23 05:36:22 DEBUG : only14: md5 = cf477f7ac3224307d47f387768b409f3 OK 2025/05/23 05:36:24 DEBUG : both15: md5 = e22ff5df8a1d09b4937d893bb5b948c8 OK 2025/05/23 05:36:25 DEBUG : only15: md5 = db4d50e8d1b35e8c3d968232470af47e OK 2025/05/23 05:36:26 DEBUG : both16: md5 = 17fc3adba1e1bfb115241504f00442f3 OK 2025/05/23 05:36:28 DEBUG : only16: md5 = 255ac8f6f2872f076a56742ee4e0e397 OK 2025/05/23 05:36:29 DEBUG : both17: md5 = 22cc9c49d01935f30fed3f429cad5d31 OK 2025/05/23 05:36:31 DEBUG : only17: md5 = 87b019cad198b355aab5e20210753c97 OK 2025/05/23 05:36:32 DEBUG : both18: md5 = 1b6a48996a1597a09284ec015eab3150 OK 2025/05/23 05:36:33 DEBUG : only18: md5 = c1aa57628eba0156ca55bd82153f5df7 OK 2025/05/23 05:36:35 DEBUG : both19: md5 = c263eea7af582368ce4d40b81b6071b7 OK 2025/05/23 05:36:36 DEBUG : only19: md5 = 6e1c89fab5895081823c382c3e44dedb OK 2025/05/23 05:36:37 DEBUG : both0: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/05/23 05:36:37 DEBUG : both1: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/05/23 05:36:37 DEBUG : both10: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/05/23 05:36:37 DEBUG : both11: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/05/23 05:36:37 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dusorix4sahe': Waiting for checks to finish 2025/05/23 05:36:37 DEBUG : both0: Unchanged skipping 2025/05/23 05:36:37 DEBUG : both12: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/05/23 05:36:37 DEBUG : both11: Unchanged skipping 2025/05/23 05:36:37 DEBUG : both13: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/05/23 05:36:37 DEBUG : both13: Unchanged skipping 2025/05/23 05:36:37 DEBUG : both14: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/05/23 05:36:37 DEBUG : both14: Unchanged skipping 2025/05/23 05:36:37 DEBUG : both15: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/05/23 05:36:37 DEBUG : both15: Unchanged skipping 2025/05/23 05:36:37 DEBUG : both16: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/05/23 05:36:37 DEBUG : both16: Unchanged skipping 2025/05/23 05:36:37 DEBUG : both17: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/05/23 05:36:37 DEBUG : both17: Unchanged skipping 2025/05/23 05:36:37 DEBUG : both18: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/05/23 05:36:37 DEBUG : both18: Unchanged skipping 2025/05/23 05:36:37 DEBUG : both19: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/05/23 05:36:37 DEBUG : both19: Unchanged skipping 2025/05/23 05:36:37 DEBUG : both2: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/05/23 05:36:37 DEBUG : both2: Unchanged skipping 2025/05/23 05:36:37 DEBUG : both3: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/05/23 05:36:37 DEBUG : both3: Unchanged skipping 2025/05/23 05:36:37 DEBUG : both4: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/05/23 05:36:37 DEBUG : both4: Unchanged skipping 2025/05/23 05:36:37 DEBUG : both5: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/05/23 05:36:37 DEBUG : both5: Unchanged skipping 2025/05/23 05:36:37 DEBUG : both6: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/05/23 05:36:37 DEBUG : both6: Unchanged skipping 2025/05/23 05:36:37 DEBUG : both7: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/05/23 05:36:37 DEBUG : both7: Unchanged skipping 2025/05/23 05:36:37 DEBUG : both8: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/05/23 05:36:37 DEBUG : both8: Unchanged skipping 2025/05/23 05:36:37 DEBUG : both9: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/05/23 05:36:37 DEBUG : both9: Unchanged skipping 2025/05/23 05:36:37 DEBUG : only0: Sizes differ (src 0 vs dst 6) 2025/05/23 05:36:37 DEBUG : only1: Sizes differ (src 0 vs dst 6) 2025/05/23 05:36:37 DEBUG : only10: Sizes differ (src 0 vs dst 6) 2025/05/23 05:36:37 DEBUG : only11: Sizes differ (src 0 vs dst 6) 2025/05/23 05:36:37 DEBUG : only12: Sizes differ (src 0 vs dst 6) 2025/05/23 05:36:37 DEBUG : only13: Sizes differ (src 0 vs dst 6) 2025/05/23 05:36:37 DEBUG : only14: Sizes differ (src 0 vs dst 6) 2025/05/23 05:36:37 DEBUG : only15: Sizes differ (src 0 vs dst 6) 2025/05/23 05:36:37 DEBUG : only16: Sizes differ (src 0 vs dst 6) 2025/05/23 05:36:37 DEBUG : only17: Sizes differ (src 0 vs dst 6) 2025/05/23 05:36:37 DEBUG : only18: Sizes differ (src 0 vs dst 6) 2025/05/23 05:36:37 DEBUG : only19: Sizes differ (src 0 vs dst 6) 2025/05/23 05:36:37 DEBUG : only2: Sizes differ (src 0 vs dst 6) 2025/05/23 05:36:37 DEBUG : only3: Sizes differ (src 0 vs dst 6) 2025/05/23 05:36:37 DEBUG : only4: Sizes differ (src 0 vs dst 6) 2025/05/23 05:36:37 DEBUG : only5: Sizes differ (src 0 vs dst 6) 2025/05/23 05:36:37 DEBUG : only6: Sizes differ (src 0 vs dst 6) 2025/05/23 05:36:37 DEBUG : only7: Sizes differ (src 0 vs dst 6) 2025/05/23 05:36:37 DEBUG : only8: Sizes differ (src 0 vs dst 6) 2025/05/23 05:36:37 DEBUG : only9: Sizes differ (src 0 vs dst 6) 2025/05/23 05:36:37 DEBUG : both1: Unchanged skipping 2025/05/23 05:36:37 DEBUG : both10: Unchanged skipping 2025/05/23 05:36:37 DEBUG : both12: Unchanged skipping 2025/05/23 05:36:37 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dusorix4sahe': Waiting for transfers to finish 2025/05/23 05:36:38 DEBUG : only10: md5 = 735692e64caec4c4b9e93e69a83a76c8 OK 2025/05/23 05:36:38 INFO : only10: Copied (replaced existing) 2025/05/23 05:36:38 DEBUG : only1: md5 = a482be0b14ea1243e3d77b8d8d07973e OK 2025/05/23 05:36:38 INFO : only1: Copied (replaced existing) 2025/05/23 05:36:38 DEBUG : only0: md5 = cffc5a7a5002f57d15009368e3102492 OK 2025/05/23 05:36:38 INFO : only0: Copied (replaced existing) 2025/05/23 05:36:38 DEBUG : only11: md5 = f5306e38c8f333d156827ce269d6468a OK 2025/05/23 05:36:38 INFO : only11: Copied (replaced existing) 2025/05/23 05:36:39 DEBUG : only12: md5 = 8e7c85fb0a977ce9be3c0461a6b1574e OK 2025/05/23 05:36:39 INFO : only12: Copied (replaced existing) 2025/05/23 05:36:39 DEBUG : only15: md5 = dc7c51ee85847755502598f2d3126fb1 OK 2025/05/23 05:36:39 INFO : only15: Copied (replaced existing) 2025/05/23 05:36:39 DEBUG : only14: md5 = 2cd11061cd41fcda2159d423901f6071 OK 2025/05/23 05:36:39 INFO : only14: Copied (replaced existing) 2025/05/23 05:36:39 DEBUG : only13: md5 = a3888de9b6193b0506d5f25ff18997db OK 2025/05/23 05:36:39 INFO : only13: Copied (replaced existing) 2025/05/23 05:36:40 DEBUG : only16: md5 = 6bb3b1471eead2edd9fecf3ca7486b47 OK 2025/05/23 05:36:40 INFO : only16: Copied (replaced existing) 2025/05/23 05:36:40 DEBUG : only18: md5 = 8b19e71f3a08231cc0a43998b7759981 OK 2025/05/23 05:36:40 INFO : only18: Copied (replaced existing) 2025/05/23 05:36:40 DEBUG : only17: md5 = 60dcdc3d5d9d52ce99b03b5b9a2a9adc OK 2025/05/23 05:36:40 INFO : only17: Copied (replaced existing) 2025/05/23 05:36:40 DEBUG : only19: md5 = f2b61f7914ca2b529cc985147c73c58d OK 2025/05/23 05:36:40 INFO : only19: Copied (replaced existing) 2025/05/23 05:36:41 DEBUG : only2: md5 = 6ef8bb4b7acfff8af8b86fa64775833d OK 2025/05/23 05:36:41 INFO : only2: Copied (replaced existing) 2025/05/23 05:36:41 DEBUG : only3: md5 = 0f23625cfc5fcf142d6286c31cf4a246 OK 2025/05/23 05:36:41 INFO : only3: Copied (replaced existing) 2025/05/23 05:36:41 DEBUG : only4: md5 = fb43d049f868c17d5097d1f84f1e2d00 OK 2025/05/23 05:36:41 INFO : only4: Copied (replaced existing) 2025/05/23 05:36:41 DEBUG : only5: md5 = d6c16a92b8a944734bd1af640f975459 OK 2025/05/23 05:36:41 INFO : only5: Copied (replaced existing) 2025/05/23 05:36:42 DEBUG : only6: md5 = f6ad3fe2e46a24b0521d3df492e9213a OK 2025/05/23 05:36:42 INFO : only6: Copied (replaced existing) 2025/05/23 05:36:42 DEBUG : only7: md5 = 15c999a38aa4f995907becec5a5bca3d OK 2025/05/23 05:36:42 INFO : only7: Copied (replaced existing) 2025/05/23 05:36:42 DEBUG : only8: md5 = 5c61b4a3490f83aa25485276278374fa OK 2025/05/23 05:36:42 INFO : only8: Copied (replaced existing) 2025/05/23 05:36:42 DEBUG : only9: md5 = dbabd54595af978f2d2da63b17986656 OK 2025/05/23 05:36:42 INFO : only9: Copied (replaced existing) 2025/05/23 05:36:42 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dusorix4sahe'", Local "Local file system at /tmp/rclone1671050868", Modify Window "1ms" --- PASS: TestSyncConcurrentTruncate (80.09s) === RUN TestSyncReplaceDirModTime run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dusorix4sahe'", Local "Local file system at /tmp/rclone1671050868", Modify Window "1ms" 2025/05/23 05:37:02 DEBUG : empty_dir: Making directory with metadata 2025/05/23 05:37:02 INFO : empty_dir: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2025/05/23 05:37:02 DEBUG : empty_on_remote: Making directory with metadata 2025/05/23 05:37:02 INFO : empty_on_remote: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2025/05/23 05:37:02 DEBUG : empty_on_remote: Making directory with metadata 2025/05/23 05:37:03 INFO : empty_on_remote: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dusorix4sahe'", Local "Local file system at /tmp/rclone1671050868", Modify Window "1ms" 2025/05/23 05:37:08 INFO : test_dir1: Set directory modification time (using DirSetModTime) 2025/05/23 05:37:08 INFO : test_dir2: Set directory modification time (using DirSetModTime) 2025/05/23 05:37:08 INFO : test_dir2/sub_dir: Set directory modification time (using DirSetModTime) 2025/05/23 05:37:08 INFO : empty_on_remote: Set directory modification time (using DirSetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dusorix4sahe'", Local "Local file system at /tmp/rclone1671050868", Modify Window "1ms" 2025/05/23 05:37:15 DEBUG : heqj02jg0dcqlem7gl0500bvp0/24g2k8bseitblkmqnie1ibl2s8: Rmdir: contains trashed file: "633fmaa0qic3kv3cladnu11pto" 2025/05/23 05:37:15 DEBUG : heqj02jg0dcqlem7gl0500bvp0: Rmdir: contains trashed file: "24g2k8bseitblkmqnie1ibl2s8" 2025/05/23 05:37:16 DEBUG : gq68srrpl0nnf394bgf7dbu9kc: Rmdir: contains trashed file: "d26uovf0miqhd1mu3c9jbseq00" --- PASS: TestSyncReplaceDirModTime (16.40s) === RUN TestSyncReplaceDirModTimeWithEmptyDirs run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dusorix4sahe'", Local "Local file system at /tmp/rclone1671050868", Modify Window "1ms" 2025/05/23 05:37:18 DEBUG : empty_dir: Making directory with metadata 2025/05/23 05:37:18 INFO : empty_dir: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2025/05/23 05:37:18 DEBUG : empty_on_remote: Making directory with metadata 2025/05/23 05:37:18 INFO : empty_on_remote: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2025/05/23 05:37:18 DEBUG : empty_on_remote: Making directory with metadata 2025/05/23 05:37:19 INFO : empty_on_remote: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dusorix4sahe'", Local "Local file system at /tmp/rclone1671050868", Modify Window "1ms" 2025/05/23 05:37:24 INFO : test_dir1: Set directory modification time (using DirSetModTime) 2025/05/23 05:37:24 INFO : test_dir2: Set directory modification time (using DirSetModTime) 2025/05/23 05:37:24 INFO : test_dir2/sub_dir: Set directory modification time (using DirSetModTime) 2025/05/23 05:37:24 INFO : empty_on_remote: Set directory modification time (using DirSetModTime) 2025/05/23 05:37:24 INFO : empty_dir: Set directory modification time (using DirSetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dusorix4sahe'", Local "Local file system at /tmp/rclone1671050868", Modify Window "1ms" 2025/05/23 05:37:31 DEBUG : heqj02jg0dcqlem7gl0500bvp0/24g2k8bseitblkmqnie1ibl2s8: Rmdir: contains trashed file: "633fmaa0qic3kv3cladnu11pto" 2025/05/23 05:37:32 DEBUG : heqj02jg0dcqlem7gl0500bvp0: Rmdir: contains trashed file: "24g2k8bseitblkmqnie1ibl2s8" 2025/05/23 05:37:33 DEBUG : gq68srrpl0nnf394bgf7dbu9kc: Rmdir: contains trashed file: "d26uovf0miqhd1mu3c9jbseq00" --- PASS: TestSyncReplaceDirModTimeWithEmptyDirs (17.12s) === RUN TestNothingToTransferWithEmptyDirs run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dusorix4sahe'", Local "Local file system at /tmp/rclone1671050868", Modify Window "1ms" 2025/05/23 05:37:35 INFO : sub dir: Set directory modification time (using DirSetModTime) 2025/05/23 05:37:35 DEBUG : sub dir: Making directory with metadata 2025/05/23 05:37:36 INFO : sub dir: Made directory with metadata (mtime=2011-12-30T12:59:59Z) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dusorix4sahe'", Local "Local file system at /tmp/rclone1671050868", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dusorix4sahe'", Local "Local file system at /tmp/rclone1671050868", Modify Window "1ms" 2025/05/23 05:37:53 INFO : sub dir2: Set directory modification time (using DirSetModTime) 2025/05/23 05:37:53 INFO : sub dir2: Set directory modification time (using DirSetModTime) 2025/05/23 05:37:53 INFO : sub dirEmpty/sub dirEmpty2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2025/05/23 05:37:53 INFO : sub dirEmpty: Set directory modification time (using DirSetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dusorix4sahe'", Local "Local file system at /tmp/rclone1671050868", Modify Window "1ms" 2025/05/23 05:38:06 DEBUG : gcsdkq814sbtppue42dpsbg8ug: Rmdir: contains trashed file: "sjuo65gk5q3r1199jselk9k9o0" 2025/05/23 05:38:07 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/37qp6d1gohacv723ij3brofbu8/i24n0ln37pa2hv8pctddeuh73o: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" 2025/05/23 05:38:08 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/37qp6d1gohacv723ij3brofbu8: Rmdir: contains trashed file: "i24n0ln37pa2hv8pctddeuh73o" 2025/05/23 05:38:08 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "37qp6d1gohacv723ij3brofbu8" 2025/05/23 05:38:09 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak" 2025/05/23 05:38:10 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak" 2025/05/23 05:38:11 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak" 2025/05/23 05:38:11 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak" 2025/05/23 05:38:12 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/4r13oncfa2rsrr82oqhsqv24ns: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" 2025/05/23 05:38:13 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc: Rmdir: contains trashed file: "4r13oncfa2rsrr82oqhsqv24ns" 2025/05/23 05:38:13 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak" 2025/05/23 05:38:13 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestNothingToTransferWithEmptyDirs (39.80s) === RUN TestNothingToTransferWithoutEmptyDirs run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dusorix4sahe'", Local "Local file system at /tmp/rclone1671050868", Modify Window "1ms" 2025/05/23 05:38:15 INFO : sub dir: Set directory modification time (using DirSetModTime) 2025/05/23 05:38:15 DEBUG : sub dir: Making directory with metadata 2025/05/23 05:38:16 INFO : sub dir: Made directory with metadata (mtime=2011-12-30T12:59:59Z) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dusorix4sahe'", Local "Local file system at /tmp/rclone1671050868", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dusorix4sahe'", Local "Local file system at /tmp/rclone1671050868", Modify Window "1ms" 2025/05/23 05:38:36 INFO : sub dir2: Set directory modification time (using DirSetModTime) 2025/05/23 05:38:37 INFO : sub dir2: Set directory modification time (using DirSetModTime) 2025/05/23 05:38:37 INFO : sub dirEmpty/sub dirEmpty2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2025/05/23 05:38:37 INFO : sub dirEmpty: Set directory modification time (using DirSetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dusorix4sahe'", Local "Local file system at /tmp/rclone1671050868", Modify Window "1ms" 2025/05/23 05:38:49 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/37qp6d1gohacv723ij3brofbu8/i24n0ln37pa2hv8pctddeuh73o: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" 2025/05/23 05:38:50 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/37qp6d1gohacv723ij3brofbu8: Rmdir: contains trashed file: "i24n0ln37pa2hv8pctddeuh73o" 2025/05/23 05:38:51 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "37qp6d1gohacv723ij3brofbu8" 2025/05/23 05:38:51 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak" 2025/05/23 05:38:52 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak" 2025/05/23 05:38:53 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak" 2025/05/23 05:38:53 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak" 2025/05/23 05:38:54 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/4r13oncfa2rsrr82oqhsqv24ns: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" 2025/05/23 05:38:55 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc: Rmdir: contains trashed file: "4r13oncfa2rsrr82oqhsqv24ns" 2025/05/23 05:38:55 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak" 2025/05/23 05:38:55 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestNothingToTransferWithoutEmptyDirs (41.91s) PASS 2025/05/23 05:38:57 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dusorix4sahe': Purge remote "./sync.test -test.v -test.timeout 1h0m0s -remote TestCryptDrive: -verbose -fast-list" - Finished OK in 15m30.144934097s (try 1/5)