"./sync.test -test.v -test.timeout 1h0m0s -remote TestCryptDrive: -verbose -fast-list" - Starting (try 1/5) 2025/04/04 05:55:17 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-suxokod1xame" 2025/04/04 05:55:17 DEBUG : Using config file from "/home/rclone/.rclone.conf" 2025/04/04 05:55:17 DEBUG : Creating backend with remote "TestDrive:crypt/5k4c2md6mve4em7b73jkmidja3fb2nbopd8em58nbtfjmjegpu8g" 2025/04/04 05:55:18 DEBUG : Creating backend with remote "/tmp/rclone1679136044" === RUN TestPipe --- PASS: TestPipe (0.00s) === RUN TestPipeConcurrent --- PASS: TestPipeConcurrent (0.04s) === RUN TestPipeOrderBy === RUN TestPipeOrderBy/#00 === RUN TestPipeOrderBy/size === RUN TestPipeOrderBy/name === RUN TestPipeOrderBy/modtime === RUN TestPipeOrderBy/size,ascending === RUN TestPipeOrderBy/name,asc === RUN TestPipeOrderBy/modtime,ascending === RUN TestPipeOrderBy/size,descending === RUN TestPipeOrderBy/name,desc === RUN TestPipeOrderBy/modtime,descending === RUN TestPipeOrderBy/size,mixed,50 === RUN TestPipeOrderBy/size,mixed,51 --- PASS: TestPipeOrderBy (0.00s) --- PASS: TestPipeOrderBy/#00 (0.00s) --- PASS: TestPipeOrderBy/size (0.00s) --- PASS: TestPipeOrderBy/name (0.00s) --- PASS: TestPipeOrderBy/modtime (0.00s) --- PASS: TestPipeOrderBy/size,ascending (0.00s) --- PASS: TestPipeOrderBy/name,asc (0.00s) --- PASS: TestPipeOrderBy/modtime,ascending (0.00s) --- PASS: TestPipeOrderBy/size,descending (0.00s) --- PASS: TestPipeOrderBy/name,desc (0.00s) --- PASS: TestPipeOrderBy/modtime,descending (0.00s) --- PASS: TestPipeOrderBy/size,mixed,50 (0.00s) --- PASS: TestPipeOrderBy/size,mixed,51 (0.00s) === RUN TestNewLess === RUN TestNewLess/blankOK === RUN TestNewLess/tooManyParts === RUN TestNewLess/tooManyParts2 === RUN TestNewLess/badMixed === RUN TestNewLess/unknownComparison === RUN TestNewLess/unknownSortDirection === RUN TestNewLess/size === RUN TestNewLess/name === RUN TestNewLess/modtime === RUN TestNewLess/size,ascending === RUN TestNewLess/name,asc === RUN TestNewLess/modtime,ascending === RUN TestNewLess/size,descending === RUN TestNewLess/name,desc === RUN TestNewLess/modtime,descending === RUN TestNewLess/modtime,mixed === RUN TestNewLess/modtime,mixed,30 --- PASS: TestNewLess (0.00s) --- PASS: TestNewLess/blankOK (0.00s) --- PASS: TestNewLess/tooManyParts (0.00s) --- PASS: TestNewLess/tooManyParts2 (0.00s) --- PASS: TestNewLess/badMixed (0.00s) --- PASS: TestNewLess/unknownComparison (0.00s) --- PASS: TestNewLess/unknownSortDirection (0.00s) --- PASS: TestNewLess/size (0.00s) --- PASS: TestNewLess/name (0.00s) --- PASS: TestNewLess/modtime (0.00s) --- PASS: TestNewLess/size,ascending (0.00s) --- PASS: TestNewLess/name,asc (0.00s) --- PASS: TestNewLess/modtime,ascending (0.00s) --- PASS: TestNewLess/size,descending (0.00s) --- PASS: TestNewLess/name,desc (0.00s) --- PASS: TestNewLess/modtime,descending (0.00s) --- PASS: TestNewLess/modtime,mixed (0.00s) --- PASS: TestNewLess/modtime,mixed,30 (0.00s) === RUN TestRcCopy rc_test.go:16: Skipping test on non local remote --- SKIP: TestRcCopy (0.00s) === RUN TestRcMove rc_test.go:16: Skipping test on non local remote --- SKIP: TestRcMove (0.00s) === RUN TestRcSync rc_test.go:16: Skipping test on non local remote --- SKIP: TestRcSync (0.00s) === RUN TestCopyWithDryRun run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-suxokod1xame'", Local "Local file system at /tmp/rclone1679136044", Modify Window "1ms" 2025/04/04 05:55:19 DEBUG : Added delayed dir = "sub dir", newDst= 2025/04/04 05:55:19 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2025/04/04 05:55:19 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-suxokod1xame': Waiting for checks to finish 2025/04/04 05:55:19 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-suxokod1xame': Waiting for transfers to finish 2025/04/04 05:55:19 NOTICE: sub dir/hello world: Skipped copy as --dry-run is set (size 11) 2025/04/04 05:55:19 NOTICE: sub dir: Skipped set directory modification time as --dry-run is set run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-suxokod1xame'", Local "Local file system at /tmp/rclone1679136044", Modify Window "1ms" --- PASS: TestCopyWithDryRun (2.08s) === RUN TestCopy run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-suxokod1xame'", Local "Local file system at /tmp/rclone1679136044", Modify Window "1ms" 2025/04/04 05:55:20 INFO : sub dir: Set directory modification time (using DirSetModTime) 2025/04/04 05:55:21 DEBUG : Added delayed dir = "sub dir", newDst= 2025/04/04 05:55:21 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2025/04/04 05:55:21 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-suxokod1xame': Waiting for checks to finish 2025/04/04 05:55:21 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-suxokod1xame': Waiting for transfers to finish 2025/04/04 05:55:23 DEBUG : sub dir/hello world: md5 = c1f60f9d586d83d32283f6a73e5afa9b OK 2025/04/04 05:55:23 INFO : sub dir/hello world: Copied (new) 2025/04/04 05:55:23 INFO : sub dir: Set directory modification time (using DirSetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-suxokod1xame'", Local "Local file system at /tmp/rclone1679136044", Modify Window "1ms" 2025/04/04 05:55:25 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestCopy (5.79s) === RUN TestCopyMetadata run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-suxokod1xame'", Local "Local file system at /tmp/rclone1679136044", Modify Window "1ms" 2025/04/04 05:55:26 DEBUG : metadata sub dir: Making directory with metadata 2025/04/04 05:55:26 INFO : metadata sub dir: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2025/04/04 05:55:26 DEBUG : empty metadata sub dir: Making directory with metadata 2025/04/04 05:55:26 INFO : empty metadata sub dir: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2025/04/04 05:55:26 DEBUG : Local file system at /tmp/rclone1679136044: File to upload is small (21 bytes), uploading instead of streaming 2025/04/04 05:55:26 DEBUG : metadata sub dir/hello metadata world: md5 = baa7a013449dbba2b1ed02b5cfb4e1a2 OK 2025/04/04 05:55:26 DEBUG : metadata sub dir/hello metadata world: Size and md5 of src and dst objects identical 2025/04/04 05:55:26 INFO : metadata sub dir: Set directory modification time (using DirSetModTime) 2025/04/04 05:55:27 DEBUG : Google drive root 'crypt/5k4c2md6mve4em7b73jkmidja3fb2nbopd8em58nbtfjmjegpu8g': Skipping btime metadata as can't update it on an existing file: 2025-04-04T05:55:26.698658187Z 2025/04/04 05:55:27 INFO : empty metadata sub dir: Updated directory metadata 2025/04/04 05:55:27 DEBUG : Google drive root 'crypt/5k4c2md6mve4em7b73jkmidja3fb2nbopd8em58nbtfjmjegpu8g': Skipping btime metadata as can't update it on an existing file: 2025-04-04T05:55:26.698658187Z 2025/04/04 05:55:28 INFO : metadata sub dir: Updated directory metadata 2025/04/04 05:55:28 DEBUG : metadata sub dir/hello metadata world: Need to transfer - File not found at Destination 2025/04/04 05:55:28 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-suxokod1xame': Waiting for checks to finish 2025/04/04 05:55:28 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-suxokod1xame': Waiting for transfers to finish 2025/04/04 05:55:29 DEBUG : metadata sub dir/hello metadata world: md5 = e685c85fa0af21c7af42d0fc6f1e727d OK 2025/04/04 05:55:29 INFO : metadata sub dir/hello metadata world: Copied (new) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-suxokod1xame'", Local "Local file system at /tmp/rclone1679136044", Modify Window "1ms" 2025/04/04 05:55:32 DEBUG : fg45q1rm3kh00nmmkk4m6ihmrcnel1p7551kqhjr9bk2gtd2gbf0: Rmdir: contains trashed file: "dmuvulfij81f693ur0f1vvbvq9v6iscp56daas3m51n9li5e3470" --- PASS: TestCopyMetadata (7.61s) === RUN TestCopyMetadataNoEmptyDirs run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-suxokod1xame'", Local "Local file system at /tmp/rclone1679136044", Modify Window "1ms" 2025/04/04 05:55:34 DEBUG : metadata sub dir: Making directory with metadata 2025/04/04 05:55:34 INFO : metadata sub dir: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2025/04/04 05:55:34 DEBUG : empty metadata sub dir: Making directory with metadata 2025/04/04 05:55:34 INFO : empty metadata sub dir: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2025/04/04 05:55:34 DEBUG : Local file system at /tmp/rclone1679136044: File to upload is small (21 bytes), uploading instead of streaming 2025/04/04 05:55:34 DEBUG : metadata sub dir/hello metadata world: md5 = baa7a013449dbba2b1ed02b5cfb4e1a2 OK 2025/04/04 05:55:34 DEBUG : metadata sub dir/hello metadata world: Size and md5 of src and dst objects identical 2025/04/04 05:55:34 INFO : metadata sub dir: Set directory modification time (using DirSetModTime) 2025/04/04 05:55:34 DEBUG : Added delayed dir = "empty metadata sub dir", newDst= 2025/04/04 05:55:34 DEBUG : Added delayed dir = "metadata sub dir", newDst= 2025/04/04 05:55:34 DEBUG : metadata sub dir/hello metadata world: Need to transfer - File not found at Destination 2025/04/04 05:55:34 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-suxokod1xame': Waiting for checks to finish 2025/04/04 05:55:34 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-suxokod1xame': Waiting for transfers to finish 2025/04/04 05:55:36 DEBUG : metadata sub dir/hello metadata world: md5 = 98f1ccb790d0f8d3c0ef850fb6b68f40 OK 2025/04/04 05:55:36 INFO : metadata sub dir/hello metadata world: Copied (new) 2025/04/04 05:55:36 DEBUG : Google drive root 'crypt/5k4c2md6mve4em7b73jkmidja3fb2nbopd8em58nbtfjmjegpu8g': Skipping btime metadata as can't update it on an existing file: 2025-04-04T05:55:34.314671477Z 2025/04/04 05:55:37 INFO : metadata sub dir: Updated directory metadata run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-suxokod1xame'", Local "Local file system at /tmp/rclone1679136044", Modify Window "1ms" 2025/04/04 05:55:40 DEBUG : fg45q1rm3kh00nmmkk4m6ihmrcnel1p7551kqhjr9bk2gtd2gbf0: Rmdir: contains trashed file: "dmuvulfij81f693ur0f1vvbvq9v6iscp56daas3m51n9li5e3470" --- PASS: TestCopyMetadataNoEmptyDirs (6.83s) === RUN TestCopyMissingDirectory run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-suxokod1xame'", Local "Local file system at /tmp/rclone1679136044", Modify Window "1ms" 2025/04/04 05:55:41 DEBUG : Creating backend with remote "/non-existing" 2025/04/04 05:55:41 ERROR : Local file system at /non-existing: error reading source root directory: directory not found 2025/04/04 05:55:41 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-suxokod1xame': Waiting for checks to finish 2025/04/04 05:55:41 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-suxokod1xame': Waiting for transfers to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-suxokod1xame'", Local "Local file system at /tmp/rclone1679136044", Modify Window "1ms" --- PASS: TestCopyMissingDirectory (1.19s) === RUN TestCopyNoTraverse run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-suxokod1xame'", Local "Local file system at /tmp/rclone1679136044", Modify Window "1ms" 2025/04/04 05:55:42 DEBUG : Added delayed dir = "sub dir", newDst= 2025/04/04 05:55:42 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2025/04/04 05:55:42 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-suxokod1xame': Waiting for checks to finish 2025/04/04 05:55:42 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-suxokod1xame': Waiting for transfers to finish 2025/04/04 05:55:44 DEBUG : sub dir/hello world: md5 = 12e6ad97e1030cd0f781dac7726b8c24 OK 2025/04/04 05:55:44 INFO : sub dir/hello world: Copied (new) 2025/04/04 05:55:45 INFO : sub dir: Set directory modification time (using DirSetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-suxokod1xame'", Local "Local file system at /tmp/rclone1679136044", Modify Window "1ms" 2025/04/04 05:55:46 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestCopyNoTraverse (5.68s) === RUN TestCopyCheckFirst run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-suxokod1xame'", Local "Local file system at /tmp/rclone1679136044", Modify Window "1ms" 2025/04/04 05:55:48 INFO : Encrypted drive 'TestCryptDrive:rclone-test-suxokod1xame': Running all checks before starting transfers 2025/04/04 05:55:48 DEBUG : Added delayed dir = "sub dir", newDst= 2025/04/04 05:55:48 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2025/04/04 05:55:48 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-suxokod1xame': Waiting for checks to finish 2025/04/04 05:55:48 INFO : Encrypted drive 'TestCryptDrive:rclone-test-suxokod1xame': Checks finished, now starting transfers 2025/04/04 05:55:48 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-suxokod1xame': Waiting for transfers to finish 2025/04/04 05:55:50 DEBUG : sub dir/hello world: md5 = 861913c537ecf3635a840285ec896b5a OK 2025/04/04 05:55:50 INFO : sub dir/hello world: Copied (new) 2025/04/04 05:55:50 INFO : sub dir: Set directory modification time (using DirSetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-suxokod1xame'", Local "Local file system at /tmp/rclone1679136044", Modify Window "1ms" 2025/04/04 05:55:52 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestCopyCheckFirst (5.64s) === RUN TestSyncNoTraverse run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-suxokod1xame'", Local "Local file system at /tmp/rclone1679136044", Modify Window "1ms" 2025/04/04 05:55:53 ERROR : Ignoring --no-traverse with sync 2025/04/04 05:55:53 DEBUG : Added delayed dir = "sub dir", newDst= 2025/04/04 05:55:53 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2025/04/04 05:55:53 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-suxokod1xame': Waiting for checks to finish 2025/04/04 05:55:53 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-suxokod1xame': Waiting for transfers to finish 2025/04/04 05:55:55 DEBUG : sub dir/hello world: md5 = 2e6882cc90046ec32490ab119f479216 OK 2025/04/04 05:55:55 INFO : sub dir/hello world: Copied (new) 2025/04/04 05:55:55 DEBUG : Waiting for deletions to finish 2025/04/04 05:55:56 INFO : sub dir: Set directory modification time (using DirSetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-suxokod1xame'", Local "Local file system at /tmp/rclone1679136044", Modify Window "1ms" 2025/04/04 05:55:58 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestSyncNoTraverse (5.84s) === RUN TestCopyWithDepth run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-suxokod1xame'", Local "Local file system at /tmp/rclone1679136044", Modify Window "1ms" 2025/04/04 05:55:59 DEBUG : hello world2: Need to transfer - File not found at Destination 2025/04/04 05:55:59 DEBUG : Added delayed dir = "sub dir", newDst= 2025/04/04 05:55:59 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-suxokod1xame': Waiting for checks to finish 2025/04/04 05:55:59 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-suxokod1xame': Waiting for transfers to finish 2025/04/04 05:56:01 DEBUG : hello world2: md5 = 9ff6b47f3df4b9b3135ed2a98189acee OK 2025/04/04 05:56:01 INFO : hello world2: Copied (new) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-suxokod1xame'", Local "Local file system at /tmp/rclone1679136044", Modify Window "1ms" --- PASS: TestCopyWithDepth (3.39s) === RUN TestCopyWithFilesFrom run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-suxokod1xame'", Local "Local file system at /tmp/rclone1679136044", Modify Window "1ms" 2025/04/04 05:56:03 DEBUG : potato2: Need to transfer - File not found at Destination 2025/04/04 05:56:03 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-suxokod1xame': Waiting for checks to finish 2025/04/04 05:56:03 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-suxokod1xame': Waiting for transfers to finish 2025/04/04 05:56:04 DEBUG : potato2: md5 = 110926e5bb727c3b1fb73936959980ce OK 2025/04/04 05:56:04 INFO : potato2: Copied (new) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-suxokod1xame'", Local "Local file system at /tmp/rclone1679136044", Modify Window "1ms" --- PASS: TestCopyWithFilesFrom (3.25s) === RUN TestCopyWithFilesFromAndNoTraverse run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-suxokod1xame'", Local "Local file system at /tmp/rclone1679136044", Modify Window "1ms" 2025/04/04 05:56:06 DEBUG : potato2: Need to transfer - File not found at Destination 2025/04/04 05:56:06 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-suxokod1xame': Waiting for checks to finish 2025/04/04 05:56:06 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-suxokod1xame': Waiting for transfers to finish 2025/04/04 05:56:07 DEBUG : potato2: md5 = adc0f8d7bdce9a766b9c4f7635ec9e11 OK 2025/04/04 05:56:07 INFO : potato2: Copied (new) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-suxokod1xame'", Local "Local file system at /tmp/rclone1679136044", Modify Window "1ms" --- PASS: TestCopyWithFilesFromAndNoTraverse (3.18s) === RUN TestCopyEmptyDirectories run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-suxokod1xame'", Local "Local file system at /tmp/rclone1679136044", Modify Window "1ms" 2025/04/04 05:56:09 DEBUG : sub dir2/sub sub dir2: Making directory with metadata 2025/04/04 05:56:09 INFO : sub dir2/sub sub dir2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2025/04/04 05:56:09 INFO : sub dir2: Set directory modification time (using DirSetModTime) 2025/04/04 05:56:09 INFO : sub dir: Set directory modification time (using DirSetModTime) 2025/04/04 05:56:09 DEBUG : sub dir: Making directory with metadata 2025/04/04 05:56:10 INFO : sub dir: Made directory with metadata (mtime=2001-02-03T04:05:06.499999999Z) 2025/04/04 05:56:10 DEBUG : sub dir2: Making directory with metadata 2025/04/04 05:56:11 INFO : sub dir2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2025/04/04 05:56:11 DEBUG : sub dir2/sub sub dir2: Making directory with metadata 2025/04/04 05:56:11 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2025/04/04 05:56:11 INFO : sub dir2/sub sub dir2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2025/04/04 05:56:11 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-suxokod1xame': Waiting for checks to finish 2025/04/04 05:56:11 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-suxokod1xame': Waiting for transfers to finish 2025/04/04 05:56:12 DEBUG : sub dir/hello world: md5 = 39cd8eba6221910db404f80707712005 OK 2025/04/04 05:56:12 INFO : sub dir/hello world: Copied (new) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-suxokod1xame'", Local "Local file system at /tmp/rclone1679136044", Modify Window "1ms" 2025/04/04 05:56:16 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc: Rmdir: contains trashed file: "cv6a9uf28ngrajena8kt5ijjn0" 2025/04/04 05:56:16 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestCopyEmptyDirectories (8.72s) === RUN TestCopyNoEmptyDirectories run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-suxokod1xame'", Local "Local file system at /tmp/rclone1679136044", Modify Window "1ms" 2025/04/04 05:56:18 INFO : sub dir2: Making directory 2025/04/04 05:56:18 DEBUG : sub dir2/sub sub dir2: Making directory with metadata 2025/04/04 05:56:18 INFO : sub dir2/sub sub dir2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2025/04/04 05:56:18 DEBUG : Added delayed dir = "sub dir", newDst= 2025/04/04 05:56:18 DEBUG : Added delayed dir = "sub dir2", newDst= 2025/04/04 05:56:18 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2025/04/04 05:56:18 DEBUG : Added delayed dir = "sub dir2/sub sub dir2", newDst= 2025/04/04 05:56:18 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-suxokod1xame': Waiting for checks to finish 2025/04/04 05:56:18 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-suxokod1xame': Waiting for transfers to finish 2025/04/04 05:56:20 DEBUG : sub dir/hello world: md5 = b88e462b0bf52c6027eb5b57bc6c89e0 OK 2025/04/04 05:56:20 INFO : sub dir/hello world: Copied (new) 2025/04/04 05:56:20 INFO : sub dir: Set directory modification time (using DirSetModTime) 2025/04/04 05:56:22 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestCopyNoEmptyDirectories (4.84s) === RUN TestMoveEmptyDirectories run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-suxokod1xame'", Local "Local file system at /tmp/rclone1679136044", Modify Window "1ms" 2025/04/04 05:56:22 DEBUG : sub dir2: Making directory with metadata 2025/04/04 05:56:22 INFO : sub dir2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2025/04/04 05:56:23 DEBUG : sub dir: Making directory with metadata 2025/04/04 05:56:23 INFO : sub dir: Made directory with metadata (mtime=2025-04-04T05:56:22.874755896Z) 2025/04/04 05:56:23 DEBUG : sub dir2: Making directory with metadata 2025/04/04 05:56:24 INFO : sub dir2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2025/04/04 05:56:24 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2025/04/04 05:56:24 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-suxokod1xame': Waiting for checks to finish 2025/04/04 05:56:24 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-suxokod1xame': Waiting for transfers to finish 2025/04/04 05:56:25 DEBUG : sub dir/hello world: md5 = b8de510caccde0d2e70d961e75bff8d5 OK 2025/04/04 05:56:25 INFO : sub dir/hello world: Copied (new) 2025/04/04 05:56:25 INFO : sub dir/hello world: Deleted run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-suxokod1xame'", Local "Local file system at /tmp/rclone1679136044", Modify Window "1ms" 2025/04/04 05:56:28 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestMoveEmptyDirectories (7.29s) === RUN TestSyncNoUpdateDirModtime run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-suxokod1xame'", Local "Local file system at /tmp/rclone1679136044", Modify Window "1ms" 2025/04/04 05:56:30 DEBUG : sub dir no update dir modtime: Making directory with metadata 2025/04/04 05:56:30 INFO : sub dir no update dir modtime: Made directory with metadata (mtime=2001-02-03T04:05:06.499999999Z) 2025/04/04 05:56:31 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-suxokod1xame': Waiting for checks to finish 2025/04/04 05:56:31 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-suxokod1xame': Waiting for transfers to finish 2025/04/04 05:56:31 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-suxokod1xame'", Local "Local file system at /tmp/rclone1679136044", Modify Window "1ms" --- PASS: TestSyncNoUpdateDirModtime (4.05s) === RUN TestMoveNoEmptyDirectories run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-suxokod1xame'", Local "Local file system at /tmp/rclone1679136044", Modify Window "1ms" 2025/04/04 05:56:34 INFO : sub dir2: Making directory 2025/04/04 05:56:34 DEBUG : Added delayed dir = "sub dir", newDst= 2025/04/04 05:56:34 DEBUG : Added delayed dir = "sub dir2", newDst= 2025/04/04 05:56:34 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2025/04/04 05:56:34 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-suxokod1xame': Waiting for checks to finish 2025/04/04 05:56:34 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-suxokod1xame': Waiting for transfers to finish 2025/04/04 05:56:36 DEBUG : sub dir/hello world: md5 = 4de4e91e189fac496b38344b7af9b30e OK 2025/04/04 05:56:36 INFO : sub dir/hello world: Copied (new) 2025/04/04 05:56:36 INFO : sub dir/hello world: Deleted 2025/04/04 05:56:36 INFO : sub dir: Set directory modification time (using DirSetModTime) 2025/04/04 05:56:38 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestMoveNoEmptyDirectories (4.94s) === RUN TestSyncEmptyDirectories run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-suxokod1xame'", Local "Local file system at /tmp/rclone1679136044", Modify Window "1ms" 2025/04/04 05:56:39 DEBUG : sub dir2: Making directory with metadata 2025/04/04 05:56:39 INFO : sub dir2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2025/04/04 05:56:39 INFO : sub dir: Set directory modification time (using DirSetModTime) 2025/04/04 05:56:39 DEBUG : sub dir: Making directory with metadata 2025/04/04 05:56:40 INFO : sub dir: Made directory with metadata (mtime=2001-02-03T04:05:06.499999999Z) 2025/04/04 05:56:40 DEBUG : sub dir2: Making directory with metadata 2025/04/04 05:56:40 INFO : sub dir2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2025/04/04 05:56:40 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2025/04/04 05:56:40 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-suxokod1xame': Waiting for checks to finish 2025/04/04 05:56:40 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-suxokod1xame': Waiting for transfers to finish 2025/04/04 05:56:42 DEBUG : sub dir/hello world: md5 = 04bd681b808c8cf83a3cce227204aca6 OK 2025/04/04 05:56:42 INFO : sub dir/hello world: Copied (new) 2025/04/04 05:56:42 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-suxokod1xame'", Local "Local file system at /tmp/rclone1679136044", Modify Window "1ms" 2025/04/04 05:56:45 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestSyncEmptyDirectories (7.22s) === RUN TestSyncSetDelayedModTimes run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-suxokod1xame'", Local "Local file system at /tmp/rclone1679136044", Modify Window "1ms" sync_test.go:507: Backend doesn't have DirModTimeUpdatesOnWrite set --- SKIP: TestSyncSetDelayedModTimes (0.48s) === RUN TestSyncNoEmptyDirectories run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-suxokod1xame'", Local "Local file system at /tmp/rclone1679136044", Modify Window "1ms" 2025/04/04 05:56:46 INFO : sub dir2: Making directory 2025/04/04 05:56:47 DEBUG : Added delayed dir = "sub dir", newDst= 2025/04/04 05:56:47 DEBUG : Added delayed dir = "sub dir2", newDst= 2025/04/04 05:56:47 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2025/04/04 05:56:47 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-suxokod1xame': Waiting for checks to finish 2025/04/04 05:56:47 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-suxokod1xame': Waiting for transfers to finish 2025/04/04 05:56:49 DEBUG : sub dir/hello world: md5 = fee9ed65f38d41f9d3bda3b85b79cd81 OK 2025/04/04 05:56:49 INFO : sub dir/hello world: Copied (new) 2025/04/04 05:56:49 DEBUG : Waiting for deletions to finish 2025/04/04 05:56:49 INFO : sub dir: Set directory modification time (using DirSetModTime) 2025/04/04 05:56:51 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestSyncNoEmptyDirectories (5.29s) === RUN TestServerSideCopy run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-suxokod1xame'", Local "Local file system at /tmp/rclone1679136044", Modify Window "1ms" 2025/04/04 05:56:54 DEBUG : sub dir/hello world: md5 = e71ff133b77a87cc6731ec832237258e OK 2025/04/04 05:56:54 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-piwanog8fuha" 2025/04/04 05:56:54 DEBUG : Config file has changed externally - reloading 2025/04/04 05:56:54 DEBUG : Creating backend with remote "TestDrive:crypt/0fji700inn2d36gn3mf9rt6l9h21msomrdf8enr9meqkjolhe030" sync_test.go:590: Server side copy (if possible) Encrypted drive 'TestCryptDrive:rclone-test-suxokod1xame' -> Encrypted drive 'TestCryptDrive:rclone-test-piwanog8fuha' 2025/04/04 05:56:56 DEBUG : Added delayed dir = "sub dir", newDst= 2025/04/04 05:56:56 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2025/04/04 05:56:56 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-piwanog8fuha': Waiting for checks to finish 2025/04/04 05:56:56 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-piwanog8fuha': Waiting for transfers to finish 2025/04/04 05:56:58 INFO : sub dir/hello world: Copied (server-side copy) 2025/04/04 05:56:59 INFO : sub dir: Set directory modification time (using DirSetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-suxokod1xame'", Local "Local file system at /tmp/rclone1679136044", Modify Window "1ms" 2025/04/04 05:56:59 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-piwanog8fuha': Purge remote 2025/04/04 05:57:01 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestServerSideCopy (10.24s) === RUN TestCopyOverSelf run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-suxokod1xame'", Local "Local file system at /tmp/rclone1679136044", Modify Window "1ms" 2025/04/04 05:57:04 DEBUG : sub dir/hello world: md5 = 8094632daf5d399c36e0d7773d53cb91 OK 2025/04/04 05:57:05 INFO : sub dir: Set directory modification time (using SetModTime) 2025/04/04 05:57:05 DEBUG : Added delayed dir = "sub dir", newDst=sub dir 2025/04/04 05:57:05 DEBUG : sub dir/hello world: Sizes differ (src 17 vs dst 11) 2025/04/04 05:57:05 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-suxokod1xame': Waiting for checks to finish 2025/04/04 05:57:05 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-suxokod1xame': Waiting for transfers to finish 2025/04/04 05:57:07 DEBUG : sub dir/hello world: md5 = 10500ce243d8595afabc76e06a5aa7a2 OK 2025/04/04 05:57:07 INFO : sub dir/hello world: Copied (replaced existing) 2025/04/04 05:57:07 INFO : sub dir: Set directory modification time (using SetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-suxokod1xame'", Local "Local file system at /tmp/rclone1679136044", Modify Window "1ms" 2025/04/04 05:57:09 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestCopyOverSelf (7.88s) === RUN TestServerSideCopyOverSelf run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-suxokod1xame'", Local "Local file system at /tmp/rclone1679136044", Modify Window "1ms" 2025/04/04 05:57:12 DEBUG : sub dir/hello world: md5 = 20b7dd266f64faab9afcea51c380a994 OK 2025/04/04 05:57:13 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-geyifud2rose" 2025/04/04 05:57:13 DEBUG : Creating backend with remote "TestDrive:crypt/kbrtfj43bg8n797ao6k8veici8vf02vmlpfn4pktolc9f51v3be0" sync_test.go:626: Server side copy (if possible) Encrypted drive 'TestCryptDrive:rclone-test-suxokod1xame' -> Encrypted drive 'TestCryptDrive:rclone-test-geyifud2rose' 2025/04/04 05:57:14 DEBUG : Added delayed dir = "sub dir", newDst= 2025/04/04 05:57:14 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2025/04/04 05:57:14 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-geyifud2rose': Waiting for checks to finish 2025/04/04 05:57:14 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-geyifud2rose': Waiting for transfers to finish 2025/04/04 05:57:17 INFO : sub dir/hello world: Copied (server-side copy) 2025/04/04 05:57:17 INFO : sub dir: Set directory modification time (using DirSetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-suxokod1xame'", Local "Local file system at /tmp/rclone1679136044", Modify Window "1ms" 2025/04/04 05:57:19 DEBUG : sub dir/hello world: md5 = 67bd91456871c7d9e1c81a835ee04425 OK 2025/04/04 05:57:20 DEBUG : sub dir: Directory modification time the same (differ by 0s, within tolerance 1ms) 2025/04/04 05:57:20 DEBUG : Added delayed dir = "sub dir", newDst=sub dir 2025/04/04 05:57:20 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-geyifud2rose': Waiting for checks to finish 2025/04/04 05:57:20 DEBUG : sub dir/hello world: Sizes differ (src 17 vs dst 11) 2025/04/04 05:57:20 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-geyifud2rose': Waiting for transfers to finish 2025/04/04 05:57:21 INFO : sub dir/hello world: Copied (server-side copy) 2025/04/04 05:57:22 INFO : sub dir: Set directory modification time (using SetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-suxokod1xame'", Local "Local file system at /tmp/rclone1679136044", Modify Window "1ms" 2025/04/04 05:57:22 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-geyifud2rose': Purge remote 2025/04/04 05:57:24 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestServerSideCopyOverSelf (15.80s) === RUN TestMoveOverSelf run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-suxokod1xame'", Local "Local file system at /tmp/rclone1679136044", Modify Window "1ms" 2025/04/04 05:57:28 DEBUG : sub dir/hello world: md5 = ab53d8b45f8fe470a24054a77e2eb372 OK 2025/04/04 05:57:29 INFO : sub dir: Set directory modification time (using SetModTime) 2025/04/04 05:57:29 DEBUG : Added delayed dir = "sub dir", newDst=sub dir 2025/04/04 05:57:29 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-suxokod1xame': Waiting for checks to finish 2025/04/04 05:57:29 DEBUG : sub dir/hello world: Sizes differ (src 17 vs dst 11) 2025/04/04 05:57:29 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-suxokod1xame': Waiting for transfers to finish 2025/04/04 05:57:30 DEBUG : sub dir/hello world: md5 = 1655f3dc9449911bbfbfe8843cbe4af6 OK 2025/04/04 05:57:30 INFO : sub dir/hello world: Copied (replaced existing) 2025/04/04 05:57:30 INFO : sub dir/hello world: Deleted 2025/04/04 05:57:31 INFO : sub dir: Set directory modification time (using SetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-suxokod1xame'", Local "Local file system at /tmp/rclone1679136044", Modify Window "1ms" 2025/04/04 05:57:32 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestMoveOverSelf (8.05s) === RUN TestServerSideMoveOverSelf run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-suxokod1xame'", Local "Local file system at /tmp/rclone1679136044", Modify Window "1ms" 2025/04/04 05:57:36 DEBUG : sub dir/hello world: md5 = 1b0b6002386d83f38c02e25512f8d54d OK 2025/04/04 05:57:36 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-huxidim6deho" 2025/04/04 05:57:36 DEBUG : Creating backend with remote "TestDrive:crypt/0j8ng0ljpnbfqhc3m3ftne5eick1eh2ltsop2t8askdftjhm2gv0" sync_test.go:671: Server side copy (if possible) Encrypted drive 'TestCryptDrive:rclone-test-suxokod1xame' -> Encrypted drive 'TestCryptDrive:rclone-test-huxidim6deho' 2025/04/04 05:57:38 DEBUG : Added delayed dir = "sub dir", newDst= 2025/04/04 05:57:38 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2025/04/04 05:57:38 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-huxidim6deho': Waiting for checks to finish 2025/04/04 05:57:38 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-huxidim6deho': Waiting for transfers to finish 2025/04/04 05:57:40 INFO : sub dir/hello world: Copied (server-side copy) 2025/04/04 05:57:40 INFO : sub dir: Set directory modification time (using DirSetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-suxokod1xame'", Local "Local file system at /tmp/rclone1679136044", Modify Window "1ms" 2025/04/04 05:57:42 DEBUG : sub dir/hello world: md5 = b979729cf3161a855fea1c03462efa09 OK 2025/04/04 05:57:43 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-huxidim6deho': Using server-side directory move 2025/04/04 05:57:43 INFO : Encrypted drive 'TestCryptDrive:rclone-test-huxidim6deho': Server side directory move failed - fallback to file moves: can't copy directory - destination already exists 2025/04/04 05:57:43 DEBUG : sub dir: Directory modification time the same (differ by 0s, within tolerance 1ms) 2025/04/04 05:57:43 DEBUG : Added delayed dir = "sub dir", newDst=sub dir 2025/04/04 05:57:43 DEBUG : sub dir/hello world: Sizes differ (src 17 vs dst 11) 2025/04/04 05:57:43 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-huxidim6deho': Waiting for checks to finish 2025/04/04 05:57:43 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-huxidim6deho': Waiting for transfers to finish 2025/04/04 05:57:44 INFO : sub dir/hello world: Deleted 2025/04/04 05:57:44 INFO : sub dir/hello world: Moved (server-side) 2025/04/04 05:57:45 INFO : sub dir: Set directory modification time (using SetModTime) 2025/04/04 05:57:47 DEBUG : sub dir/hello world: md5 = f95db7e1767af424924a5fb3065781a4 OK 2025/04/04 05:57:48 DEBUG : testing file moves 2025/04/04 05:57:48 DEBUG : sub dir: Directory modification time the same (differ by 0s, within tolerance 1ms) 2025/04/04 05:57:48 DEBUG : Added delayed dir = "sub dir", newDst=sub dir 2025/04/04 05:57:48 DEBUG : sub dir/hello world: Sizes differ (src 24 vs dst 17) 2025/04/04 05:57:48 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-huxidim6deho': Waiting for checks to finish 2025/04/04 05:57:48 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-huxidim6deho': Waiting for transfers to finish 2025/04/04 05:57:49 INFO : sub dir/hello world: Deleted 2025/04/04 05:57:49 INFO : sub dir/hello world: Moved (server-side) 2025/04/04 05:57:50 INFO : sub dir: Set directory modification time (using SetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-suxokod1xame'", Local "Local file system at /tmp/rclone1679136044", Modify Window "1ms" 2025/04/04 05:57:51 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-huxidim6deho': Purge remote --- PASS: TestServerSideMoveOverSelf (19.63s) === RUN TestCopyAfterDelete run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-suxokod1xame'", Local "Local file system at /tmp/rclone1679136044", Modify Window "1ms" 2025/04/04 05:57:55 DEBUG : sub dir/hello world: md5 = 12875ed7c667f1418f95156683bf87c6 OK 2025/04/04 05:57:55 ERROR : : error listing: directory not found 2025/04/04 05:57:56 INFO : Local file system at /tmp/rclone1679136044: Making directory 2025/04/04 05:57:56 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-suxokod1xame': Waiting for checks to finish 2025/04/04 05:57:56 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-suxokod1xame': Waiting for transfers to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-suxokod1xame'", Local "Local file system at /tmp/rclone1679136044", Modify Window "1ms" 2025/04/04 05:57:58 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestCopyAfterDelete (5.94s) === RUN TestCopyRedownload run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-suxokod1xame'", Local "Local file system at /tmp/rclone1679136044", Modify Window "1ms" 2025/04/04 05:58:01 DEBUG : sub dir/hello world: md5 = 65324ea0d74dff92d2700d987c43349f OK 2025/04/04 05:58:02 DEBUG : Added delayed dir = "sub dir", newDst= 2025/04/04 05:58:02 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2025/04/04 05:58:02 DEBUG : Local file system at /tmp/rclone1679136044: Waiting for checks to finish 2025/04/04 05:58:02 DEBUG : Local file system at /tmp/rclone1679136044: Waiting for transfers to finish 2025/04/04 05:58:03 DEBUG : sub dir/hello world.285f0a30.partial: renamed to: sub dir/hello world 2025/04/04 05:58:03 INFO : sub dir/hello world: Copied (new) 2025/04/04 05:58:03 INFO : sub dir: Set directory modification time (using DirSetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-suxokod1xame'", Local "Local file system at /tmp/rclone1679136044", Modify Window "1ms" 2025/04/04 05:58:04 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestCopyRedownload (6.69s) === RUN TestSyncBasedOnCheckSum run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-suxokod1xame'", Local "Local file system at /tmp/rclone1679136044", Modify Window "1ms" 2025/04/04 05:58:06 DEBUG : check sum: Need to transfer - File not found at Destination 2025/04/04 05:58:06 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-suxokod1xame': Waiting for checks to finish 2025/04/04 05:58:06 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-suxokod1xame': Waiting for transfers to finish 2025/04/04 05:58:08 DEBUG : check sum: md5 = 843555f5d556459f2ab7e32c5d01c5d2 OK 2025/04/04 05:58:08 INFO : check sum: Copied (new) 2025/04/04 05:58:08 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-suxokod1xame'", Local "Local file system at /tmp/rclone1679136044", Modify Window "1ms" 2025/04/04 05:58:08 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-suxokod1xame': Waiting for checks to finish 2025/04/04 05:58:08 NOTICE: Encrypted drive 'TestCryptDrive:rclone-test-suxokod1xame': --checksum is in use but the source and destination have no hashes in common; falling back to --size-only 2025/04/04 05:58:08 DEBUG : check sum: Size of src and dst objects identical 2025/04/04 05:58:08 DEBUG : check sum: Unchanged skipping 2025/04/04 05:58:08 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-suxokod1xame': Waiting for transfers to finish 2025/04/04 05:58:08 DEBUG : Waiting for deletions to finish 2025/04/04 05:58:08 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-suxokod1xame'", Local "Local file system at /tmp/rclone1679136044", Modify Window "1ms" --- PASS: TestSyncBasedOnCheckSum (4.18s) === RUN TestSyncSizeOnly run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-suxokod1xame'", Local "Local file system at /tmp/rclone1679136044", Modify Window "1ms" 2025/04/04 05:58:10 DEBUG : sizeonly: Need to transfer - File not found at Destination 2025/04/04 05:58:10 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-suxokod1xame': Waiting for checks to finish 2025/04/04 05:58:10 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-suxokod1xame': Waiting for transfers to finish 2025/04/04 05:58:12 DEBUG : sizeonly: md5 = 25654fc8b9aca043cc4c5337424f96d0 OK 2025/04/04 05:58:12 INFO : sizeonly: Copied (new) 2025/04/04 05:58:12 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-suxokod1xame'", Local "Local file system at /tmp/rclone1679136044", Modify Window "1ms" 2025/04/04 05:58:12 DEBUG : sizeonly: Sizes identical 2025/04/04 05:58:12 DEBUG : sizeonly: Unchanged skipping 2025/04/04 05:58:12 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-suxokod1xame': Waiting for checks to finish 2025/04/04 05:58:12 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-suxokod1xame': Waiting for transfers to finish 2025/04/04 05:58:12 DEBUG : Waiting for deletions to finish 2025/04/04 05:58:12 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-suxokod1xame'", Local "Local file system at /tmp/rclone1679136044", Modify Window "1ms" --- PASS: TestSyncSizeOnly (4.22s) === RUN TestSyncIgnoreSize run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-suxokod1xame'", Local "Local file system at /tmp/rclone1679136044", Modify Window "1ms" 2025/04/04 05:58:15 DEBUG : ignore-size: Need to transfer - File not found at Destination 2025/04/04 05:58:15 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-suxokod1xame': Waiting for checks to finish 2025/04/04 05:58:15 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-suxokod1xame': Waiting for transfers to finish 2025/04/04 05:58:16 DEBUG : ignore-size: md5 = aee99a2f9d5cdaaad11602556aa270d6 OK 2025/04/04 05:58:16 INFO : ignore-size: Copied (new) 2025/04/04 05:58:16 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-suxokod1xame'", Local "Local file system at /tmp/rclone1679136044", Modify Window "1ms" 2025/04/04 05:58:16 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-suxokod1xame': Waiting for checks to finish 2025/04/04 05:58:16 DEBUG : ignore-size: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/04 05:58:16 DEBUG : ignore-size: Unchanged skipping 2025/04/04 05:58:16 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-suxokod1xame': Waiting for transfers to finish 2025/04/04 05:58:16 DEBUG : Waiting for deletions to finish 2025/04/04 05:58:16 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-suxokod1xame'", Local "Local file system at /tmp/rclone1679136044", Modify Window "1ms" --- PASS: TestSyncIgnoreSize (4.06s) === RUN TestSyncIgnoreTimes run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-suxokod1xame'", Local "Local file system at /tmp/rclone1679136044", Modify Window "1ms" 2025/04/04 05:58:20 DEBUG : existing: md5 = 019ad6e618f47f869732af6b174ae74f OK 2025/04/04 05:58:20 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-suxokod1xame': Waiting for checks to finish 2025/04/04 05:58:20 DEBUG : existing: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/04 05:58:20 DEBUG : existing: Unchanged skipping 2025/04/04 05:58:20 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-suxokod1xame': Waiting for transfers to finish 2025/04/04 05:58:20 DEBUG : Waiting for deletions to finish 2025/04/04 05:58:20 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-suxokod1xame'", Local "Local file system at /tmp/rclone1679136044", Modify Window "1ms" 2025/04/04 05:58:21 DEBUG : existing: Transferring unconditionally as --ignore-times is in use 2025/04/04 05:58:21 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-suxokod1xame': Waiting for checks to finish 2025/04/04 05:58:21 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-suxokod1xame': Waiting for transfers to finish 2025/04/04 05:58:22 DEBUG : existing: md5 = cea854581a8f4d7abbdadd05636bc848 OK 2025/04/04 05:58:22 INFO : existing: Copied (replaced existing) 2025/04/04 05:58:22 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-suxokod1xame'", Local "Local file system at /tmp/rclone1679136044", Modify Window "1ms" --- PASS: TestSyncIgnoreTimes (5.43s) === RUN TestSyncIgnoreExisting run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-suxokod1xame'", Local "Local file system at /tmp/rclone1679136044", Modify Window "1ms" 2025/04/04 05:58:24 DEBUG : existing: Need to transfer - File not found at Destination 2025/04/04 05:58:24 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-suxokod1xame': Waiting for checks to finish 2025/04/04 05:58:24 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-suxokod1xame': Waiting for transfers to finish 2025/04/04 05:58:25 DEBUG : existing: md5 = 29889d46399f1b58ae2563a7c40c1054 OK 2025/04/04 05:58:25 INFO : existing: Copied (new) 2025/04/04 05:58:25 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-suxokod1xame'", Local "Local file system at /tmp/rclone1679136044", Modify Window "1ms" 2025/04/04 05:58:26 DEBUG : existing: Destination exists, skipping 2025/04/04 05:58:26 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-suxokod1xame': Waiting for checks to finish 2025/04/04 05:58:26 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-suxokod1xame': Waiting for transfers to finish 2025/04/04 05:58:26 DEBUG : Waiting for deletions to finish 2025/04/04 05:58:26 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-suxokod1xame'", Local "Local file system at /tmp/rclone1679136044", Modify Window "1ms" --- PASS: TestSyncIgnoreExisting (4.16s) === RUN TestSyncIgnoreErrors run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-suxokod1xame'", Local "Local file system at /tmp/rclone1679136044", Modify Window "1ms" 2025/04/04 05:58:30 DEBUG : b/potato: md5 = f11468e543a5ab50353aa96ff4261819 OK 2025/04/04 05:58:32 DEBUG : c/non empty space: md5 = cd8e9698b42ad50c15cd9ac3554c47d0 OK 2025/04/04 05:58:32 INFO : d: Making directory 2025/04/04 05:58:34 DEBUG : Added delayed dir = "a", newDst= 2025/04/04 05:58:34 INFO : c: Set directory modification time (using SetModTime) 2025/04/04 05:58:34 DEBUG : Added delayed dir = "c", newDst=c 2025/04/04 05:58:34 DEBUG : c/non empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/04/04 05:58:34 DEBUG : a/potato2: Need to transfer - File not found at Destination 2025/04/04 05:58:34 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-suxokod1xame': Waiting for checks to finish 2025/04/04 05:58:34 DEBUG : c/non empty space: Unchanged skipping 2025/04/04 05:58:34 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-suxokod1xame': Waiting for transfers to finish 2025/04/04 05:58:37 DEBUG : a/potato2: md5 = 3f434bf0cacab0404ffc19a4b12544e9 OK 2025/04/04 05:58:37 INFO : a/potato2: Copied (new) 2025/04/04 05:58:37 DEBUG : Waiting for deletions to finish 2025/04/04 05:58:37 INFO : b/potato: Deleted 2025/04/04 05:58:37 INFO : a: Set directory modification time (using DirSetModTime) 2025/04/04 05:58:37 INFO : d: Removing directory 2025/04/04 05:58:38 INFO : b: Removing directory 2025/04/04 05:58:38 DEBUG : 32d8ua6196mc1r7qkfog53rkg0: Rmdir: contains trashed file: "2m507n64kafsi59v9q71r281a4" 2025/04/04 05:58:39 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-suxokod1xame': deleted 2 directories run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-suxokod1xame'", Local "Local file system at /tmp/rclone1679136044", Modify Window "1ms" 2025/04/04 05:58:41 DEBUG : 3i9du405pfogq3ncai6pg7ouio: Rmdir: contains trashed file: "982d3pss7t5pn0il16r2foj31s" 2025/04/04 05:58:42 DEBUG : 2bsvlrk2ne1lfitm6tttcu0qt8: Rmdir: contains trashed file: "89l8renevh3mji1c8r1p7qn6tg" --- PASS: TestSyncIgnoreErrors (14.94s) === RUN TestSyncAfterChangingModtimeOnly run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-suxokod1xame'", Local "Local file system at /tmp/rclone1679136044", Modify Window "1ms" 2025/04/04 05:58:44 DEBUG : empty space: md5 = a729687d66042015fa1ba8aef4439956 OK 2025/04/04 05:58:45 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-suxokod1xame': Waiting for checks to finish 2025/04/04 05:58:45 DEBUG : empty space: Modification times differ by -95456h54m52.624456789s: 2011-12-25 12:59:59.123456789 +0000 UTC, 2001-02-03 04:05:06.499 +0000 UTC 2025/04/04 05:58:45 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-suxokod1xame': Waiting for transfers to finish 2025/04/04 05:58:45 NOTICE: empty space: Skipped copy as --dry-run is set (size 1) 2025/04/04 05:58:45 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-suxokod1xame'", Local "Local file system at /tmp/rclone1679136044", Modify Window "1ms" 2025/04/04 05:58:45 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-suxokod1xame': Waiting for checks to finish 2025/04/04 05:58:45 DEBUG : empty space: Modification times differ by -95456h54m52.624456789s: 2011-12-25 12:59:59.123456789 +0000 UTC, 2001-02-03 04:05:06.499 +0000 UTC 2025/04/04 05:58:45 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-suxokod1xame': Waiting for transfers to finish 2025/04/04 05:58:46 DEBUG : empty space: md5 = 0ea6d4b8b662e969caa19c5c8a5c558e OK 2025/04/04 05:58:46 INFO : empty space: Copied (replaced existing) 2025/04/04 05:58:46 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-suxokod1xame'", Local "Local file system at /tmp/rclone1679136044", Modify Window "1ms" --- PASS: TestSyncAfterChangingModtimeOnly (5.63s) === RUN TestSyncAfterChangingModtimeOnlyWithNoUpdateModTime run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-suxokod1xame'", Local "Local file system at /tmp/rclone1679136044", Modify Window "1ms" sync_test.go:1016: Can't check this if no hashes supported --- PASS: TestSyncAfterChangingModtimeOnlyWithNoUpdateModTime (0.44s) === RUN TestSyncDoesntUpdateModtime run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-suxokod1xame'", Local "Local file system at /tmp/rclone1679136044", Modify Window "1ms" 2025/04/04 05:58:50 DEBUG : foo: md5 = e0d9af4b1cc160d31196e7cc5241c025 OK 2025/04/04 05:58:51 DEBUG : foo: Modification times differ by -95456h54m52.624456789s: 2011-12-25 12:59:59.123456789 +0000 UTC, 2001-02-03 04:05:06.499 +0000 UTC 2025/04/04 05:58:51 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-suxokod1xame': Waiting for checks to finish 2025/04/04 05:58:51 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-suxokod1xame': Waiting for transfers to finish 2025/04/04 05:58:52 DEBUG : foo: md5 = 7f3538dbac7b2c5110bb12de7d37b3db OK 2025/04/04 05:58:52 INFO : foo: Copied (replaced existing) 2025/04/04 05:58:52 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-suxokod1xame'", Local "Local file system at /tmp/rclone1679136044", Modify Window "1ms" --- PASS: TestSyncDoesntUpdateModtime (4.65s) === RUN TestSyncAfterAddingAFile run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-suxokod1xame'", Local "Local file system at /tmp/rclone1679136044", Modify Window "1ms" 2025/04/04 05:58:55 DEBUG : empty space: md5 = a477fe01ca5d4a832fbedc731f66d920 OK 2025/04/04 05:58:55 DEBUG : potato: Need to transfer - File not found at Destination 2025/04/04 05:58:55 DEBUG : empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/04/04 05:58:55 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-suxokod1xame': Waiting for checks to finish 2025/04/04 05:58:55 DEBUG : empty space: Unchanged skipping 2025/04/04 05:58:55 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-suxokod1xame': Waiting for transfers to finish 2025/04/04 05:58:57 DEBUG : potato: md5 = f259c037fcff87a69496abf3d5ab7c1b OK 2025/04/04 05:58:57 INFO : potato: Copied (new) 2025/04/04 05:58:57 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-suxokod1xame'", Local "Local file system at /tmp/rclone1679136044", Modify Window "1ms" --- PASS: TestSyncAfterAddingAFile (5.00s) === RUN TestSyncAfterChangingFilesSizeOnly run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-suxokod1xame'", Local "Local file system at /tmp/rclone1679136044", Modify Window "1ms" 2025/04/04 05:59:00 DEBUG : potato: md5 = a9006357d493b500c768b8769dcd3c88 OK 2025/04/04 05:59:00 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-suxokod1xame': Waiting for checks to finish 2025/04/04 05:59:00 DEBUG : potato: Sizes differ (src 21 vs dst 60) 2025/04/04 05:59:00 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-suxokod1xame': Waiting for transfers to finish 2025/04/04 05:59:01 DEBUG : potato: md5 = 0f721243df41b79b2e0b7c8e6b6585dc OK 2025/04/04 05:59:01 INFO : potato: Copied (replaced existing) 2025/04/04 05:59:01 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-suxokod1xame'", Local "Local file system at /tmp/rclone1679136044", Modify Window "1ms" --- PASS: TestSyncAfterChangingFilesSizeOnly (4.39s) === RUN TestSyncAfterChangingContentsOnly run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-suxokod1xame'", Local "Local file system at /tmp/rclone1679136044", Modify Window "1ms" 2025/04/04 05:59:04 DEBUG : potato: md5 = 531f06ccab2f1fa27c010c66cbbc39be OK 2025/04/04 05:59:05 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-suxokod1xame': Waiting for checks to finish 2025/04/04 05:59:05 DEBUG : potato: Modification times differ by 119h59m59.876543211s: 2011-12-25 12:59:59.123456789 +0000 UTC, 2011-12-30 12:59:59 +0000 UTC 2025/04/04 05:59:05 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-suxokod1xame': Waiting for transfers to finish 2025/04/04 05:59:06 DEBUG : potato: md5 = 58ea09377e927894a2bed88f91a27581 OK 2025/04/04 05:59:06 INFO : potato: Copied (replaced existing) 2025/04/04 05:59:06 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-suxokod1xame'", Local "Local file system at /tmp/rclone1679136044", Modify Window "1ms" --- PASS: TestSyncAfterChangingContentsOnly (4.56s) === RUN TestSyncAfterRemovingAFileAndAddingAFileDryRun run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-suxokod1xame'", Local "Local file system at /tmp/rclone1679136044", Modify Window "1ms" 2025/04/04 05:59:09 DEBUG : potato: md5 = a5bf1ecd19ebf49c176a38237e37089f OK 2025/04/04 05:59:10 DEBUG : empty space: md5 = 445db36ae3cebd8d31ee3145d94421e0 OK 2025/04/04 05:59:10 DEBUG : potato2: Need to transfer - File not found at Destination 2025/04/04 05:59:10 DEBUG : empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/04/04 05:59:10 DEBUG : empty space: Unchanged skipping 2025/04/04 05:59:10 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-suxokod1xame': Waiting for checks to finish 2025/04/04 05:59:10 NOTICE: potato2: Skipped copy as --dry-run is set (size 60) 2025/04/04 05:59:10 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-suxokod1xame': Waiting for transfers to finish 2025/04/04 05:59:10 DEBUG : Waiting for deletions to finish 2025/04/04 05:59:10 NOTICE: potato: Skipped delete as --dry-run is set (size 21) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-suxokod1xame'", Local "Local file system at /tmp/rclone1679136044", Modify Window "1ms" --- PASS: TestSyncAfterRemovingAFileAndAddingAFileDryRun (4.74s) === RUN TestSyncAfterRemovingAFileAndAddingAFile run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-suxokod1xame'", Local "Local file system at /tmp/rclone1679136044", Modify Window "1ms" 2025/04/04 05:59:14 DEBUG : potato: md5 = 3cddeec0d76db0d64e9e26f2585a4e02 OK 2025/04/04 05:59:15 DEBUG : empty space: md5 = 865c46384c7058610b47baa46812fac2 OK 2025/04/04 05:59:15 DEBUG : potato2: Need to transfer - File not found at Destination 2025/04/04 05:59:15 DEBUG : empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/04/04 05:59:15 DEBUG : empty space: Unchanged skipping 2025/04/04 05:59:15 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-suxokod1xame': Waiting for checks to finish 2025/04/04 05:59:15 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-suxokod1xame': Waiting for transfers to finish 2025/04/04 05:59:17 DEBUG : potato2: md5 = c96078104883d4229cc7a0f1c4b9641b OK 2025/04/04 05:59:17 INFO : potato2: Copied (new) 2025/04/04 05:59:17 DEBUG : Waiting for deletions to finish 2025/04/04 05:59:17 INFO : potato: Deleted run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-suxokod1xame'", Local "Local file system at /tmp/rclone1679136044", Modify Window "1ms" --- PASS: TestSyncAfterRemovingAFileAndAddingAFile (6.91s) === RUN TestSyncAfterRemovingAFileAndAddingAFileSubDir run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-suxokod1xame'", Local "Local file system at /tmp/rclone1679136044", Modify Window "1ms" 2025/04/04 05:59:21 DEBUG : b/potato: md5 = 7adda136e9cefcaad335a0cff64277d3 OK 2025/04/04 05:59:24 DEBUG : c/non empty space: md5 = aeadd1fa118ae9abdd73dd56e0b8dbcc OK 2025/04/04 05:59:24 INFO : d: Making directory 2025/04/04 05:59:24 INFO : d/e: Making directory 2025/04/04 05:59:27 DEBUG : Added delayed dir = "a", newDst= 2025/04/04 05:59:27 INFO : c: Set directory modification time (using SetModTime) 2025/04/04 05:59:27 DEBUG : Added delayed dir = "c", newDst=c 2025/04/04 05:59:27 DEBUG : c/non empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/04/04 05:59:27 DEBUG : a/potato2: Need to transfer - File not found at Destination 2025/04/04 05:59:27 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-suxokod1xame': Waiting for checks to finish 2025/04/04 05:59:27 DEBUG : c/non empty space: Unchanged skipping 2025/04/04 05:59:27 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-suxokod1xame': Waiting for transfers to finish 2025/04/04 05:59:30 DEBUG : a/potato2: md5 = 0c9c60d9125cb7a776f3de0e3ef8251a OK 2025/04/04 05:59:30 INFO : a/potato2: Copied (new) 2025/04/04 05:59:30 DEBUG : Waiting for deletions to finish 2025/04/04 05:59:30 INFO : b/potato: Deleted 2025/04/04 05:59:31 INFO : a: Set directory modification time (using DirSetModTime) 2025/04/04 05:59:31 INFO : d/e: Removing directory 2025/04/04 05:59:31 INFO : d: Removing directory 2025/04/04 05:59:31 DEBUG : ka6id8d20d3s5ktapedlphgta8: Rmdir: contains trashed file: "r8sppajuabeak3sbgj2ak8vuf8" 2025/04/04 05:59:32 INFO : b: Removing directory 2025/04/04 05:59:32 DEBUG : 32d8ua6196mc1r7qkfog53rkg0: Rmdir: contains trashed file: "2m507n64kafsi59v9q71r281a4" 2025/04/04 05:59:33 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-suxokod1xame': deleted 3 directories run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-suxokod1xame'", Local "Local file system at /tmp/rclone1679136044", Modify Window "1ms" 2025/04/04 05:59:35 DEBUG : 3i9du405pfogq3ncai6pg7ouio: Rmdir: contains trashed file: "982d3pss7t5pn0il16r2foj31s" 2025/04/04 05:59:35 DEBUG : 2bsvlrk2ne1lfitm6tttcu0qt8: Rmdir: contains trashed file: "89l8renevh3mji1c8r1p7qn6tg" --- PASS: TestSyncAfterRemovingAFileAndAddingAFileSubDir (17.25s) === RUN TestSyncAfterRemovingAFileAndAddingAFileSubDirWithErrors run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-suxokod1xame'", Local "Local file system at /tmp/rclone1679136044", Modify Window "1ms" 2025/04/04 05:59:38 DEBUG : b/potato: md5 = 05469c2919ec99341b90e871ce9d7b25 OK 2025/04/04 05:59:41 DEBUG : c/non empty space: md5 = 77bdba0e9f6652bef057f482fc242364 OK 2025/04/04 05:59:41 INFO : d: Making directory 2025/04/04 05:59:42 DEBUG : Added delayed dir = "a", newDst= 2025/04/04 05:59:43 INFO : c: Set directory modification time (using SetModTime) 2025/04/04 05:59:43 DEBUG : Added delayed dir = "c", newDst=c 2025/04/04 05:59:43 DEBUG : c/non empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/04/04 05:59:43 DEBUG : a/potato2: Need to transfer - File not found at Destination 2025/04/04 05:59:43 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-suxokod1xame': Waiting for checks to finish 2025/04/04 05:59:43 DEBUG : c/non empty space: Unchanged skipping 2025/04/04 05:59:43 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-suxokod1xame': Waiting for transfers to finish 2025/04/04 05:59:45 DEBUG : a/potato2: md5 = 6948cc1fd021ea8f65a574f804ed23d9 OK 2025/04/04 05:59:45 INFO : a/potato2: Copied (new) 2025/04/04 05:59:45 ERROR : Encrypted drive 'TestCryptDrive:rclone-test-suxokod1xame': not deleting files as there were IO errors 2025/04/04 05:59:46 INFO : a: Set directory modification time (using DirSetModTime) 2025/04/04 05:59:46 ERROR : Encrypted drive 'TestCryptDrive:rclone-test-suxokod1xame': not deleting directories as there were IO errors run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-suxokod1xame'", Local "Local file system at /tmp/rclone1679136044", Modify Window "1ms" 2025/04/04 05:59:49 DEBUG : 3i9du405pfogq3ncai6pg7ouio: Rmdir: contains trashed file: "982d3pss7t5pn0il16r2foj31s" 2025/04/04 05:59:49 DEBUG : 32d8ua6196mc1r7qkfog53rkg0: Rmdir: contains trashed file: "2m507n64kafsi59v9q71r281a4" 2025/04/04 05:59:50 DEBUG : 2bsvlrk2ne1lfitm6tttcu0qt8: Rmdir: contains trashed file: "89l8renevh3mji1c8r1p7qn6tg" --- PASS: TestSyncAfterRemovingAFileAndAddingAFileSubDirWithErrors (14.76s) === RUN TestSyncDeleteAfter --- PASS: TestSyncDeleteAfter (0.00s) === RUN TestSyncDeleteDuring run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-suxokod1xame'", Local "Local file system at /tmp/rclone1679136044", Modify Window "1ms" 2025/04/04 05:59:53 DEBUG : potato: md5 = 4122c43ab7de0384d991bdfb6dc10eef OK 2025/04/04 05:59:54 DEBUG : empty space: md5 = addee8cd2226e571fe16515e7b0c4d72 OK 2025/04/04 05:59:54 DEBUG : Waiting for deletions to finish 2025/04/04 05:59:55 DEBUG : potato2: Need to transfer - File not found at Destination 2025/04/04 05:59:55 DEBUG : empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/04/04 05:59:55 DEBUG : empty space: Unchanged skipping 2025/04/04 05:59:55 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-suxokod1xame': Waiting for checks to finish 2025/04/04 05:59:55 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-suxokod1xame': Waiting for transfers to finish 2025/04/04 05:59:55 INFO : potato: Deleted 2025/04/04 05:59:56 DEBUG : potato2: md5 = e6a457cd4222251e5ebdcd49afe3bff3 OK 2025/04/04 05:59:56 INFO : potato2: Copied (new) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-suxokod1xame'", Local "Local file system at /tmp/rclone1679136044", Modify Window "1ms" --- PASS: TestSyncDeleteDuring (6.67s) === RUN TestSyncDeleteBefore run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-suxokod1xame'", Local "Local file system at /tmp/rclone1679136044", Modify Window "1ms" 2025/04/04 05:59:59 DEBUG : potato: md5 = f887379e061fba3c0d1e3a63c971fcde OK 2025/04/04 06:00:00 DEBUG : empty space: md5 = 9e4d2dac3bb881a90eca19455ee73453 OK 2025/04/04 06:00:01 DEBUG : Waiting for deletions to finish 2025/04/04 06:00:01 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-suxokod1xame': Waiting for checks to finish 2025/04/04 06:00:01 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-suxokod1xame': Waiting for transfers to finish 2025/04/04 06:00:01 INFO : potato: Deleted 2025/04/04 06:00:02 DEBUG : potato2: Need to transfer - File not found at Destination 2025/04/04 06:00:02 DEBUG : empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/04/04 06:00:02 DEBUG : empty space: Unchanged skipping 2025/04/04 06:00:02 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-suxokod1xame': Waiting for checks to finish 2025/04/04 06:00:02 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-suxokod1xame': Waiting for transfers to finish 2025/04/04 06:00:03 DEBUG : potato2: md5 = b8fd65c527d0e55156a14c5358f59ff8 OK 2025/04/04 06:00:03 INFO : potato2: Copied (new) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-suxokod1xame'", Local "Local file system at /tmp/rclone1679136044", Modify Window "1ms" --- PASS: TestSyncDeleteBefore (7.06s) === RUN TestCopyDeleteBefore run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-suxokod1xame'", Local "Local file system at /tmp/rclone1679136044", Modify Window "1ms" 2025/04/04 06:00:06 DEBUG : potato: md5 = aa25cda52f0c885aa9401ffdd3103067 OK 2025/04/04 06:00:07 DEBUG : potato2: Need to transfer - File not found at Destination 2025/04/04 06:00:07 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-suxokod1xame': Waiting for checks to finish 2025/04/04 06:00:07 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-suxokod1xame': Waiting for transfers to finish 2025/04/04 06:00:08 DEBUG : potato2: md5 = 5050e7eeaf5ef3cef98f2dad5b0b2f0a OK 2025/04/04 06:00:08 INFO : potato2: Copied (new) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-suxokod1xame'", Local "Local file system at /tmp/rclone1679136044", Modify Window "1ms" --- PASS: TestCopyDeleteBefore (5.06s) === RUN TestSyncWithExclude run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-suxokod1xame'", Local "Local file system at /tmp/rclone1679136044", Modify Window "1ms" 2025/04/04 06:00:11 DEBUG : potato2: md5 = 199178b8497ef1932b79d5f5bc3d4965 OK 2025/04/04 06:00:13 DEBUG : empty space: md5 = 345a202c2866bbd6ac7c07dddfe74558 OK 2025/04/04 06:00:13 DEBUG : enormous: Excluded (Size Filter) 2025/04/04 06:00:13 DEBUG : enormous: Excluded 2025/04/04 06:00:13 DEBUG : potato2: Excluded (Size Filter) 2025/04/04 06:00:13 DEBUG : potato2: Excluded 2025/04/04 06:00:13 DEBUG : potato2: Excluded (Size Filter) 2025/04/04 06:00:13 DEBUG : empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/04/04 06:00:13 DEBUG : empty space: Unchanged skipping 2025/04/04 06:00:13 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-suxokod1xame': Waiting for checks to finish 2025/04/04 06:00:13 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-suxokod1xame': Waiting for transfers to finish 2025/04/04 06:00:13 DEBUG : Waiting for deletions to finish 2025/04/04 06:00:13 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-suxokod1xame'", Local "Local file system at /tmp/rclone1679136044", Modify Window "1ms" 2025/04/04 06:00:13 DEBUG : enormous: Excluded (Size Filter) 2025/04/04 06:00:13 DEBUG : enormous: Excluded 2025/04/04 06:00:13 DEBUG : potato2: Excluded (Size Filter) 2025/04/04 06:00:13 DEBUG : potato2: Excluded 2025/04/04 06:00:14 DEBUG : potato2: Excluded (Size Filter) 2025/04/04 06:00:14 DEBUG : empty space: Size and modification time the same (differ by 456.789µs, within tolerance 1ms) 2025/04/04 06:00:14 DEBUG : empty space: Unchanged skipping 2025/04/04 06:00:14 DEBUG : Local file system at /tmp/rclone1679136044: Waiting for checks to finish 2025/04/04 06:00:14 DEBUG : Local file system at /tmp/rclone1679136044: Waiting for transfers to finish 2025/04/04 06:00:14 DEBUG : Waiting for deletions to finish 2025/04/04 06:00:14 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-suxokod1xame'", Local "Local file system at /tmp/rclone1679136044", Modify Window "1ms" --- PASS: TestSyncWithExclude (5.90s) === RUN TestSyncWithExcludeAndDeleteExcluded run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-suxokod1xame'", Local "Local file system at /tmp/rclone1679136044", Modify Window "1ms" 2025/04/04 06:00:17 DEBUG : potato2: md5 = bc94fb7512d054fcfe7a825000aa7e34 OK 2025/04/04 06:00:19 DEBUG : empty space: md5 = 96d585d6bdeb4e15e1f3d22204561e75 OK 2025/04/04 06:00:20 DEBUG : enormous: md5 = 283e4fa41d2b35a4a8186f17499c279d OK 2025/04/04 06:00:20 DEBUG : enormous: Excluded (Size Filter) 2025/04/04 06:00:20 DEBUG : enormous: Excluded 2025/04/04 06:00:20 DEBUG : potato2: Excluded (Size Filter) 2025/04/04 06:00:20 DEBUG : potato2: Excluded 2025/04/04 06:00:20 DEBUG : empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/04/04 06:00:20 DEBUG : empty space: Unchanged skipping 2025/04/04 06:00:20 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-suxokod1xame': Waiting for checks to finish 2025/04/04 06:00:20 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-suxokod1xame': Waiting for transfers to finish 2025/04/04 06:00:20 DEBUG : Waiting for deletions to finish 2025/04/04 06:00:21 INFO : potato2: Deleted 2025/04/04 06:00:21 INFO : enormous: Deleted 2025/04/04 06:00:21 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-suxokod1xame'", Local "Local file system at /tmp/rclone1679136044", Modify Window "1ms" 2025/04/04 06:00:21 DEBUG : empty space: Size and modification time the same (differ by 456.789µs, within tolerance 1ms) 2025/04/04 06:00:21 DEBUG : empty space: Unchanged skipping 2025/04/04 06:00:21 DEBUG : Local file system at /tmp/rclone1679136044: Waiting for checks to finish 2025/04/04 06:00:21 DEBUG : Local file system at /tmp/rclone1679136044: Waiting for transfers to finish 2025/04/04 06:00:21 DEBUG : Waiting for deletions to finish 2025/04/04 06:00:21 INFO : enormous: Deleted 2025/04/04 06:00:21 INFO : potato2: Deleted 2025/04/04 06:00:21 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-suxokod1xame'", Local "Local file system at /tmp/rclone1679136044", Modify Window "1ms" --- PASS: TestSyncWithExcludeAndDeleteExcluded (7.40s) === RUN TestSyncWithUpdateOlder run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-suxokod1xame'", Local "Local file system at /tmp/rclone1679136044", Modify Window "1ms" 2025/04/04 06:00:25 DEBUG : one: md5 = 18d8ae2cc5c33ca75b0928795f6080a5 OK 2025/04/04 06:00:26 DEBUG : two: md5 = 864d3f2521bb8da1406bf34b33456c28 OK 2025/04/04 06:00:27 DEBUG : three: md5 = ab95d8b17881ae38438bb05e526c9209 OK 2025/04/04 06:00:29 DEBUG : four: md5 = fc23016cec0d950d2916a3f9834a42b9 OK 2025/04/04 06:00:30 DEBUG : five: Need to transfer - File not found at Destination 2025/04/04 06:00:30 DEBUG : four: Sizes differ (src 4 vs dst 8) 2025/04/04 06:00:30 DEBUG : four: Destination mod time is within 1s of source but files differ, transferring 2025/04/04 06:00:30 DEBUG : one: Destination is newer than source, skipping 2025/04/04 06:00:30 DEBUG : three: Sizes identical 2025/04/04 06:00:30 DEBUG : three: Destination mod time is within 1s of source and files identical, skipping 2025/04/04 06:00:30 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-suxokod1xame': Waiting for checks to finish 2025/04/04 06:00:30 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-suxokod1xame': Waiting for transfers to finish 2025/04/04 06:00:31 DEBUG : two: md5 = 3c2a8cd65fa3304d12c99461b237c94e OK 2025/04/04 06:00:31 INFO : two: Copied (replaced existing) 2025/04/04 06:00:31 DEBUG : four: md5 = 0c1f525f843179c44aec54c6df32d2db OK 2025/04/04 06:00:31 INFO : four: Copied (replaced existing) 2025/04/04 06:00:31 DEBUG : five: md5 = 732f28a55deae95495735bec9a626fcf OK 2025/04/04 06:00:31 INFO : five: Copied (new) 2025/04/04 06:00:31 DEBUG : Waiting for deletions to finish sync_test.go:1449: Skip test with --checksum as no hashes supported --- PASS: TestSyncWithUpdateOlder (10.73s) === 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-suxokod1xame'", Local "Local file system at /tmp/rclone1679136044", Modify Window "1ms" sync_test.go:1538: Can track renames: false 2025/04/04 06:00:34 ERROR : Encrypted drive 'TestCryptDrive:rclone-test-suxokod1xame': Ignoring --track-renames as the source and destination do not have a common hash 2025/04/04 06:00:34 DEBUG : potato: Need to transfer - File not found at Destination 2025/04/04 06:00:34 DEBUG : yam: Need to transfer - File not found at Destination 2025/04/04 06:00:34 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-suxokod1xame': Waiting for checks to finish 2025/04/04 06:00:34 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-suxokod1xame': Waiting for transfers to finish 2025/04/04 06:00:36 DEBUG : potato: md5 = cb56d29a777887794891e14554e0ac92 OK 2025/04/04 06:00:36 INFO : potato: Copied (new) 2025/04/04 06:00:36 DEBUG : yam: md5 = 1cc97de4d9f67649f111b36ea096dca7 OK 2025/04/04 06:00:36 INFO : yam: Copied (new) 2025/04/04 06:00:36 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-suxokod1xame'", Local "Local file system at /tmp/rclone1679136044", Modify Window "1ms" 2025/04/04 06:00:36 ERROR : Encrypted drive 'TestCryptDrive:rclone-test-suxokod1xame': Ignoring --track-renames as the source and destination do not have a common hash 2025/04/04 06:00:36 DEBUG : yaml: Need to transfer - File not found at Destination 2025/04/04 06:00:36 DEBUG : potato: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/04 06:00:36 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-suxokod1xame': Waiting for checks to finish 2025/04/04 06:00:36 DEBUG : potato: Unchanged skipping 2025/04/04 06:00:36 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-suxokod1xame': Waiting for transfers to finish 2025/04/04 06:00:38 DEBUG : yaml: md5 = 3576dcde446ec244eb7ca98f427e53b5 OK 2025/04/04 06:00:38 INFO : yaml: Copied (new) 2025/04/04 06:00:38 DEBUG : Waiting for deletions to finish 2025/04/04 06:00:38 INFO : yam: Deleted run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-suxokod1xame'", Local "Local file system at /tmp/rclone1679136044", Modify Window "1ms" --- PASS: TestSyncWithTrackRenames (6.43s) === RUN TestParseRenamesStrategyModtime --- PASS: TestParseRenamesStrategyModtime (0.00s) === RUN TestRenamesStrategyModtime --- PASS: TestRenamesStrategyModtime (0.00s) === RUN TestSyncWithTrackRenamesStrategyModtime run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-suxokod1xame'", Local "Local file system at /tmp/rclone1679136044", Modify Window "1ms" sync_test.go:1610: Can track renames: true 2025/04/04 06:00:41 INFO : Encrypted drive 'TestCryptDrive:rclone-test-suxokod1xame': Making map for --track-renames 2025/04/04 06:00:41 INFO : Encrypted drive 'TestCryptDrive:rclone-test-suxokod1xame': Finished making map for --track-renames 2025/04/04 06:00:41 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-suxokod1xame': Waiting for checks to finish 2025/04/04 06:00:41 DEBUG : potato: Need to transfer - No matching file found at Destination 2025/04/04 06:00:41 DEBUG : yam: Need to transfer - No matching file found at Destination 2025/04/04 06:00:41 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-suxokod1xame': Waiting for renames to finish 2025/04/04 06:00:41 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-suxokod1xame': Waiting for transfers to finish 2025/04/04 06:00:42 DEBUG : yam: md5 = b127788514795f1e8a928d3f01e556d4 OK 2025/04/04 06:00:42 INFO : yam: Copied (new) 2025/04/04 06:00:42 DEBUG : potato: md5 = 8223abb05ad1a328e40592df3bbbf8c3 OK 2025/04/04 06:00:42 INFO : potato: Copied (new) 2025/04/04 06:00:42 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-suxokod1xame'", Local "Local file system at /tmp/rclone1679136044", Modify Window "1ms" 2025/04/04 06:00:43 DEBUG : potato: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/04 06:00:43 INFO : Encrypted drive 'TestCryptDrive:rclone-test-suxokod1xame': Making map for --track-renames 2025/04/04 06:00:43 INFO : Encrypted drive 'TestCryptDrive:rclone-test-suxokod1xame': Finished making map for --track-renames 2025/04/04 06:00:43 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-suxokod1xame': Waiting for checks to finish 2025/04/04 06:00:43 DEBUG : potato: Unchanged skipping 2025/04/04 06:00:43 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-suxokod1xame': Waiting for renames to finish 2025/04/04 06:00:43 INFO : yam: Moved (server-side) to: yaml 2025/04/04 06:00:43 INFO : yaml: Renamed from "yam" 2025/04/04 06:00:43 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-suxokod1xame': Waiting for transfers to finish 2025/04/04 06:00:43 DEBUG : Waiting for deletions to finish 2025/04/04 06:00:43 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-suxokod1xame'", Local "Local file system at /tmp/rclone1679136044", Modify Window "1ms" --- PASS: TestSyncWithTrackRenamesStrategyModtime (5.65s) === RUN TestSyncWithTrackRenamesStrategyLeaf run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-suxokod1xame'", Local "Local file system at /tmp/rclone1679136044", Modify Window "1ms" sync_test.go:1649: Can track renames: true 2025/04/04 06:00:46 DEBUG : Added delayed dir = "sub", newDst= 2025/04/04 06:00:46 INFO : Encrypted drive 'TestCryptDrive:rclone-test-suxokod1xame': Making map for --track-renames 2025/04/04 06:00:46 INFO : Encrypted drive 'TestCryptDrive:rclone-test-suxokod1xame': Finished making map for --track-renames 2025/04/04 06:00:46 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-suxokod1xame': Waiting for checks to finish 2025/04/04 06:00:46 DEBUG : potato: Need to transfer - No matching file found at Destination 2025/04/04 06:00:46 DEBUG : sub/yam: Need to transfer - No matching file found at Destination 2025/04/04 06:00:46 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-suxokod1xame': Waiting for renames to finish 2025/04/04 06:00:46 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-suxokod1xame': Waiting for transfers to finish 2025/04/04 06:00:48 DEBUG : potato: md5 = 39e6753b784b42a69f883533979e2a0c OK 2025/04/04 06:00:48 INFO : potato: Copied (new) 2025/04/04 06:00:48 DEBUG : sub/yam: md5 = 0f92be7bacb0bde60fcc33d1c06fad40 OK 2025/04/04 06:00:48 INFO : sub/yam: Copied (new) 2025/04/04 06:00:48 DEBUG : Waiting for deletions to finish 2025/04/04 06:00:49 INFO : sub: Set directory modification time (using DirSetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-suxokod1xame'", Local "Local file system at /tmp/rclone1679136044", Modify Window "1ms" 2025/04/04 06:00:50 DEBUG : potato: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/04 06:00:50 DEBUG : potato: Unchanged skipping 2025/04/04 06:00:50 INFO : sub: Set directory modification time (using SetModTime) 2025/04/04 06:00:50 DEBUG : Added delayed dir = "sub", newDst=sub 2025/04/04 06:00:50 INFO : Encrypted drive 'TestCryptDrive:rclone-test-suxokod1xame': Making map for --track-renames 2025/04/04 06:00:50 INFO : Encrypted drive 'TestCryptDrive:rclone-test-suxokod1xame': Finished making map for --track-renames 2025/04/04 06:00:50 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-suxokod1xame': Waiting for checks to finish 2025/04/04 06:00:50 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-suxokod1xame': Waiting for renames to finish 2025/04/04 06:00:51 INFO : sub/yam: Moved (server-side) to: yam 2025/04/04 06:00:51 INFO : yam: Renamed from "sub/yam" 2025/04/04 06:00:51 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-suxokod1xame': Waiting for transfers to finish 2025/04/04 06:00:51 DEBUG : Waiting for deletions to finish 2025/04/04 06:00:51 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-suxokod1xame'", Local "Local file system at /tmp/rclone1679136044", Modify Window "1ms" --- PASS: TestSyncWithTrackRenamesStrategyLeaf (8.69s) === RUN TestServerSideMoveLocal run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-suxokod1xame'", Local "Local file system at /tmp/rclone1679136044", Modify Window "1ms" 2025/04/04 06:00:55 DEBUG : Creating backend with remote "/tmp/rclone1679136044/dir1" 2025/04/04 06:00:55 DEBUG : Creating backend with remote "/tmp/rclone1679136044/dir2" 2025/04/04 06:00:55 DEBUG : Local file system at /tmp/rclone1679136044/dir2: Using server-side directory move 2025/04/04 06:00:55 INFO : Local file system at /tmp/rclone1679136044/dir2: Server side directory move failed - fallback to file moves: can't copy directory - destination already exists 2025/04/04 06:00:55 DEBUG : file1.txt: Need to transfer - File not found at Destination 2025/04/04 06:00:55 INFO : file1.txt: Moved (server-side) 2025/04/04 06:00:55 DEBUG : Local file system at /tmp/rclone1679136044/dir2: Waiting for checks to finish 2025/04/04 06:00:55 DEBUG : Local file system at /tmp/rclone1679136044/dir2: Waiting for transfers to finish --- PASS: TestServerSideMoveLocal (0.49s) === RUN TestMoveWithDeleteEmptySrcDirs run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-suxokod1xame'", Local "Local file system at /tmp/rclone1679136044", Modify Window "1ms" 2025/04/04 06:00:56 DEBUG : Added delayed dir = "nested", newDst= 2025/04/04 06:00:56 DEBUG : Added delayed dir = "sub dir", newDst= 2025/04/04 06:00:56 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2025/04/04 06:00:56 DEBUG : Added delayed dir = "nested/sub dir", newDst= 2025/04/04 06:00:56 DEBUG : nested/sub dir/file: Need to transfer - File not found at Destination 2025/04/04 06:00:56 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-suxokod1xame': Waiting for checks to finish 2025/04/04 06:00:56 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-suxokod1xame': Waiting for transfers to finish 2025/04/04 06:00:58 DEBUG : sub dir/hello world: md5 = 79f25fc97543db5bdcd12cfa71344bd3 OK 2025/04/04 06:00:58 INFO : sub dir/hello world: Copied (new) 2025/04/04 06:00:58 INFO : sub dir/hello world: Deleted 2025/04/04 06:00:59 DEBUG : nested/sub dir/file: md5 = 3b4aa4ac688f34efbf31fd24b65d145d OK 2025/04/04 06:00:59 INFO : nested/sub dir/file: Copied (new) 2025/04/04 06:00:59 INFO : nested/sub dir/file: Deleted 2025/04/04 06:01:00 INFO : nested/sub dir: Set directory modification time (using DirSetModTime) 2025/04/04 06:01:00 INFO : nested: Set directory modification time (using DirSetModTime) 2025/04/04 06:01:00 INFO : sub dir: Set directory modification time (using DirSetModTime) 2025/04/04 06:01:00 INFO : sub dir: Removing directory 2025/04/04 06:01:00 INFO : nested/sub dir: Removing directory 2025/04/04 06:01:00 INFO : nested: Removing directory 2025/04/04 06:01:00 DEBUG : Local file system at /tmp/rclone1679136044: deleted 3 directories run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-suxokod1xame'", Local "Local file system at /tmp/rclone1679136044", Modify Window "1ms" 2025/04/04 06:01:03 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" 2025/04/04 06:01:04 DEBUG : 37qp6d1gohacv723ij3brofbu8/14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "ftp4kuv8se7tqduu6pmmcvjsmk" 2025/04/04 06:01:04 DEBUG : 37qp6d1gohacv723ij3brofbu8: Rmdir: contains trashed file: "14begaa36ih249fgrnfk6nulg0" --- PASS: TestMoveWithDeleteEmptySrcDirs (10.23s) === RUN TestMoveWithoutDeleteEmptySrcDirs run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-suxokod1xame'", Local "Local file system at /tmp/rclone1679136044", Modify Window "1ms" 2025/04/04 06:01:06 DEBUG : Added delayed dir = "nested", newDst= 2025/04/04 06:01:06 DEBUG : Added delayed dir = "sub dir", newDst= 2025/04/04 06:01:06 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2025/04/04 06:01:06 DEBUG : Added delayed dir = "nested/sub dir", newDst= 2025/04/04 06:01:06 DEBUG : nested/sub dir/file: Need to transfer - File not found at Destination 2025/04/04 06:01:06 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-suxokod1xame': Waiting for checks to finish 2025/04/04 06:01:06 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-suxokod1xame': Waiting for transfers to finish 2025/04/04 06:01:08 DEBUG : sub dir/hello world: md5 = 052ec03b87b3933ceb95636d9a6d12ca OK 2025/04/04 06:01:08 INFO : sub dir/hello world: Copied (new) 2025/04/04 06:01:08 INFO : sub dir/hello world: Deleted 2025/04/04 06:01:10 DEBUG : nested/sub dir/file: md5 = 6858bf319f1011d0da2a9b0a531c4760 OK 2025/04/04 06:01:10 INFO : nested/sub dir/file: Copied (new) 2025/04/04 06:01:10 INFO : nested/sub dir/file: Deleted 2025/04/04 06:01:10 INFO : nested/sub dir: Set directory modification time (using DirSetModTime) 2025/04/04 06:01:11 INFO : sub dir: Set directory modification time (using DirSetModTime) 2025/04/04 06:01:11 INFO : nested: Set directory modification time (using DirSetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-suxokod1xame'", Local "Local file system at /tmp/rclone1679136044", Modify Window "1ms" 2025/04/04 06:01:13 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" 2025/04/04 06:01:14 DEBUG : 37qp6d1gohacv723ij3brofbu8/14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "ftp4kuv8se7tqduu6pmmcvjsmk" 2025/04/04 06:01:15 DEBUG : 37qp6d1gohacv723ij3brofbu8: Rmdir: contains trashed file: "14begaa36ih249fgrnfk6nulg0" --- PASS: TestMoveWithoutDeleteEmptySrcDirs (10.14s) === RUN TestMoveWithIgnoreExisting run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-suxokod1xame'", Local "Local file system at /tmp/rclone1679136044", Modify Window "1ms" 2025/04/04 06:01:16 DEBUG : existing: Need to transfer - File not found at Destination 2025/04/04 06:01:16 DEBUG : existing-b: Need to transfer - File not found at Destination 2025/04/04 06:01:16 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-suxokod1xame': Waiting for checks to finish 2025/04/04 06:01:16 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-suxokod1xame': Waiting for transfers to finish 2025/04/04 06:01:17 DEBUG : existing-b: md5 = f7cc6c5c2345c1cefa511671863a2b30 OK 2025/04/04 06:01:17 INFO : existing-b: Copied (new) 2025/04/04 06:01:17 INFO : existing-b: Deleted 2025/04/04 06:01:17 DEBUG : existing: md5 = dd3c7a6bc297b002ee3896a60fdd2c36 OK 2025/04/04 06:01:17 INFO : existing: Copied (new) 2025/04/04 06:01:17 INFO : existing: Deleted 2025/04/04 06:01:18 DEBUG : existing: Destination exists, skipping 2025/04/04 06:01:18 DEBUG : existing: Not removing source file as destination file exists and --ignore-existing is set 2025/04/04 06:01:18 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-suxokod1xame': Waiting for checks to finish 2025/04/04 06:01:18 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-suxokod1xame': Waiting for transfers to finish 2025/04/04 06:01:18 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-suxokod1xame'", Local "Local file system at /tmp/rclone1679136044", Modify Window "1ms" --- PASS: TestMoveWithIgnoreExisting (4.50s) === RUN TestServerSideMove run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-suxokod1xame'", Local "Local file system at /tmp/rclone1679136044", Modify Window "1ms" 2025/04/04 06:01:20 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-pehugog8fika" 2025/04/04 06:01:20 DEBUG : Creating backend with remote "TestDrive:crypt/13qnim0roa2es4vtb9o5ktsbmrpbu77ns8r4l9vmhhfkad9o2ecg" 2025/04/04 06:01:22 DEBUG : potato2: md5 = 4f35c8de47ea36fb5e24077abb1df693 OK 2025/04/04 06:01:24 DEBUG : empty space: md5 = 269aa31e61b0a3d023c9e80d39f8a956 OK 2025/04/04 06:01:25 DEBUG : potato3: md5 = 3110107fc0eeb342876fa3a716ec2710 OK sync_test.go:1705: Server side move (if possible) Encrypted drive 'TestCryptDrive:rclone-test-suxokod1xame' -> Encrypted drive 'TestCryptDrive:rclone-test-pehugog8fika' 2025/04/04 06:01:28 DEBUG : empty space: md5 = 3dce4355aa51d518f90ac8dbf78e85c9 OK 2025/04/04 06:01:29 DEBUG : potato3: md5 = da3046d982de76f1d85ce8fbf7f96d1e OK 2025/04/04 06:01:29 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pehugog8fika': Using server-side directory move 2025/04/04 06:01:29 INFO : Encrypted drive 'TestCryptDrive:rclone-test-pehugog8fika': Server side directory move failed - fallback to file moves: can't copy directory - destination already exists 2025/04/04 06:01:29 DEBUG : potato2: Need to transfer - File not found at Destination 2025/04/04 06:01:29 DEBUG : empty space: Size and modification time the same (differ by 0s, within tolerance 1ms) 2025/04/04 06:01:29 DEBUG : empty space: Unchanged skipping 2025/04/04 06:01:29 DEBUG : potato3: Sizes differ (src 68 vs dst 60) 2025/04/04 06:01:29 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pehugog8fika': Waiting for checks to finish 2025/04/04 06:01:30 INFO : potato3: Deleted 2025/04/04 06:01:30 INFO : empty space: Deleted 2025/04/04 06:01:30 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pehugog8fika': Waiting for transfers to finish 2025/04/04 06:01:30 INFO : potato2: Moved (server-side) 2025/04/04 06:01:30 INFO : potato3: Moved (server-side) 2025/04/04 06:01:31 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-jewuquv7jeni" 2025/04/04 06:01:31 DEBUG : Creating backend with remote "TestDrive:crypt/om5nnv5ceu9gat5att7oqdtfi4eg4dck84ut6fbh7t57qjemipn0" 2025/04/04 06:01:32 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-jewuquv7jeni': Using server-side directory move 2025/04/04 06:01:33 INFO : Encrypted drive 'TestCryptDrive:rclone-test-jewuquv7jeni': Server side directory move succeeded 2025/04/04 06:01:34 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-jewuquv7jeni': Purge remote 2025/04/04 06:01:34 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pehugog8fika': Purge remote 2025/04/04 06:01:34 NOTICE: purge failed: directory not found --- PASS: TestServerSideMove (14.46s) === RUN TestServerSideMoveWithFilter run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-suxokod1xame'", Local "Local file system at /tmp/rclone1679136044", Modify Window "1ms" 2025/04/04 06:01:35 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-tinutax2kela" 2025/04/04 06:01:35 DEBUG : Creating backend with remote "TestDrive:crypt/ogrgml3kggvatlob9qkkfp1p323t8s7f6lkc70jg27fki027l290" 2025/04/04 06:01:37 DEBUG : potato2: md5 = 4e74175b8bc32af4c519f3601eecc8a7 OK 2025/04/04 06:01:38 DEBUG : empty space: md5 = 8243463bd245a36de8b63a28b21ecc26 OK 2025/04/04 06:01:40 DEBUG : potato3: md5 = b44fa7d2d0b9c892e6247301c5ab225f OK sync_test.go:1705: Server side move (if possible) Encrypted drive 'TestCryptDrive:rclone-test-suxokod1xame' -> Encrypted drive 'TestCryptDrive:rclone-test-tinutax2kela' 2025/04/04 06:01:42 DEBUG : empty space: md5 = 073c04fe812e94ebc8e1ec3dffa424f7 OK 2025/04/04 06:01:43 DEBUG : potato3: md5 = a326ad34bbcc1a21b828c60f644d2678 OK 2025/04/04 06:01:44 DEBUG : empty space: Excluded (Size Filter) 2025/04/04 06:01:44 DEBUG : empty space: Excluded (Size Filter) 2025/04/04 06:01:44 DEBUG : potato2: Need to transfer - File not found at Destination 2025/04/04 06:01:44 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tinutax2kela': Waiting for checks to finish 2025/04/04 06:01:44 DEBUG : potato3: Sizes differ (src 68 vs dst 60) 2025/04/04 06:01:44 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tinutax2kela': Waiting for transfers to finish 2025/04/04 06:01:44 INFO : potato3: Deleted 2025/04/04 06:01:45 INFO : potato2: Moved (server-side) 2025/04/04 06:01:45 INFO : potato3: Moved (server-side) 2025/04/04 06:01:45 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-lefineq9vupu" 2025/04/04 06:01:46 DEBUG : Creating backend with remote "TestDrive:crypt/ve8bjim8m7e90gdm7vhd22fhegp8vohsvanmrrog7f2crbcs62d0" 2025/04/04 06:01:47 DEBUG : empty space: Excluded (Size Filter) 2025/04/04 06:01:47 DEBUG : potato2: Need to transfer - File not found at Destination 2025/04/04 06:01:47 DEBUG : potato3: Need to transfer - File not found at Destination 2025/04/04 06:01:47 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-lefineq9vupu': Waiting for checks to finish 2025/04/04 06:01:47 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-lefineq9vupu': Waiting for transfers to finish 2025/04/04 06:01:48 INFO : potato2: Moved (server-side) 2025/04/04 06:01:48 INFO : potato3: Moved (server-side) 2025/04/04 06:01:49 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-lefineq9vupu': Purge remote 2025/04/04 06:01:49 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tinutax2kela': Purge remote --- PASS: TestServerSideMoveWithFilter (15.97s) === RUN TestServerSideMoveDeleteEmptySourceDirs run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-suxokod1xame'", Local "Local file system at /tmp/rclone1679136044", Modify Window "1ms" 2025/04/04 06:01:51 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-hifobic1tene" 2025/04/04 06:01:51 DEBUG : Creating backend with remote "TestDrive:crypt/0bvm6sqq6vcjbergc5g2hg7kq089m56j26bs9d3a8l70ha7s0a90" 2025/04/04 06:01:53 DEBUG : potato2: md5 = 51334e657358cbcf09214082b7585b2e OK 2025/04/04 06:01:54 DEBUG : empty space: md5 = 50017eb683b7de6caf183334af364525 OK 2025/04/04 06:01:56 DEBUG : potato3: md5 = 3755c5826931cfd83230d1a99ae8dec0 OK 2025/04/04 06:01:56 INFO : tomatoDir: Making directory sync_test.go:1705: Server side move (if possible) Encrypted drive 'TestCryptDrive:rclone-test-suxokod1xame' -> Encrypted drive 'TestCryptDrive:rclone-test-hifobic1tene' 2025/04/04 06:01:59 DEBUG : empty space: md5 = d0ab6c475776d4929061347828c9e5fb OK 2025/04/04 06:02:00 DEBUG : potato3: md5 = 581cf8889aa417377e09b6938b52a960 OK 2025/04/04 06:02:01 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hifobic1tene': Using server-side directory move 2025/04/04 06:02:01 INFO : Encrypted drive 'TestCryptDrive:rclone-test-hifobic1tene': Server side directory move failed - fallback to file moves: can't copy directory - destination already exists 2025/04/04 06:02:01 DEBUG : potato2: Need to transfer - File not found at Destination 2025/04/04 06:02:01 DEBUG : Added delayed dir = "tomatoDir", newDst= 2025/04/04 06:02:01 DEBUG : empty space: Size and modification time the same (differ by 0s, within tolerance 1ms) 2025/04/04 06:02:01 DEBUG : empty space: Unchanged skipping 2025/04/04 06:02:01 DEBUG : potato3: Sizes differ (src 68 vs dst 60) 2025/04/04 06:02:01 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hifobic1tene': Waiting for checks to finish 2025/04/04 06:02:02 INFO : empty space: Deleted 2025/04/04 06:02:02 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hifobic1tene': Waiting for transfers to finish 2025/04/04 06:02:02 INFO : potato3: Deleted 2025/04/04 06:02:02 INFO : potato2: Moved (server-side) 2025/04/04 06:02:02 INFO : potato3: Moved (server-side) 2025/04/04 06:02:02 INFO : tomatoDir: Removing directory 2025/04/04 06:02:03 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-suxokod1xame': deleted 1 directories 2025/04/04 06:02:03 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-jadewol2wiva" 2025/04/04 06:02:04 DEBUG : Creating backend with remote "TestDrive:crypt/27in87cdi40b5ngc4pi60auhrn6a646mdkt49caalndscacsglcg" 2025/04/04 06:02:05 INFO : tomatoDir: Making directory 2025/04/04 06:02:06 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-jadewol2wiva': Using server-side directory move 2025/04/04 06:02:07 INFO : Encrypted drive 'TestCryptDrive:rclone-test-jadewol2wiva': Server side directory move succeeded 2025/04/04 06:02:08 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-jadewol2wiva': Purge remote 2025/04/04 06:02:09 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hifobic1tene': Purge remote 2025/04/04 06:02:09 NOTICE: purge failed: directory not found --- PASS: TestServerSideMoveDeleteEmptySourceDirs (18.88s) === RUN TestServerSideMoveOverlap run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-suxokod1xame'", Local "Local file system at /tmp/rclone1679136044", Modify Window "1ms" sync_test.go:1910: Skipping test as remote supports DirMove --- SKIP: TestServerSideMoveOverlap (0.43s) === RUN TestSyncOverlap run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-suxokod1xame'", Local "Local file system at /tmp/rclone1679136044", Modify Window "1ms" 2025/04/04 06:02:10 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-suxokod1xame/rclone-sync-test" 2025/04/04 06:02:10 DEBUG : Creating backend with remote "TestDrive:crypt/5k4c2md6mve4em7b73jkmidja3fb2nbopd8em58nbtfjmjegpu8g/i7355aa0sb89uagn75vfjqr6s3e3e1h2et8in57abn1fe8qfego0" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-suxokod1xame'", Local "Local file system at /tmp/rclone1679136044", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-suxokod1xame'", Local "Local file system at /tmp/rclone1679136044", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-suxokod1xame'", Local "Local file system at /tmp/rclone1679136044", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-suxokod1xame'", Local "Local file system at /tmp/rclone1679136044", Modify Window "1ms" --- PASS: TestSyncOverlap (3.81s) === RUN TestSyncOverlapWithFilter run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-suxokod1xame'", Local "Local file system at /tmp/rclone1679136044", Modify Window "1ms" 2025/04/04 06:02:14 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-suxokod1xame/rclone-sync-test" 2025/04/04 06:02:14 DEBUG : Creating backend with remote "TestDrive:crypt/5k4c2md6mve4em7b73jkmidja3fb2nbopd8em58nbtfjmjegpu8g/i7355aa0sb89uagn75vfjqr6s3e3e1h2et8in57abn1fe8qfego0" 2025/04/04 06:02:16 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-suxokod1xame/rclone-sync-test-include/layer2" 2025/04/04 06:02:16 DEBUG : Creating backend with remote "TestDrive:crypt/5k4c2md6mve4em7b73jkmidja3fb2nbopd8em58nbtfjmjegpu8g/khf2vlblvnbf9ftevqm0htmss73hj1j5a7q328e4ohrgs7e2loe0/n01jpl9202nn9ec1rb75h0f1c4" 2025/04/04 06:02:19 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-suxokod1xame/rclone-sync-test-ignore-file" 2025/04/04 06:02:19 DEBUG : Creating backend with remote "TestDrive:crypt/5k4c2md6mve4em7b73jkmidja3fb2nbopd8em58nbtfjmjegpu8g/kmf11jujl9uha3tjganvgpkn45bu778hb5vb5riug1c26b38k7sg" 2025/04/04 06:02:23 DEBUG : rclone-sync-test-ignore-file/.ignore: md5 = a6d38b0ecad954e8272ba655a8a48f0e OK 2025/04/04 06:02:25 DEBUG : Added delayed dir = "rclone-sync-test-include", newDst= 2025/04/04 06:02:25 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-suxokod1xame/rclone-sync-test': Waiting for checks to finish 2025/04/04 06:02:25 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-suxokod1xame/rclone-sync-test': Waiting for transfers to finish 2025/04/04 06:02:25 DEBUG : Waiting for deletions to finish 2025/04/04 06:02:25 INFO : There was nothing to transfer 2025/04/04 06:02:27 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-suxokod1xame': Waiting for checks to finish 2025/04/04 06:02:27 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-suxokod1xame': Waiting for transfers to finish 2025/04/04 06:02:27 DEBUG : Waiting for deletions to finish 2025/04/04 06:02:27 INFO : rclone-sync-test-include: Removing directory 2025/04/04 06:02:27 DEBUG : khf2vlblvnbf9ftevqm0htmss73hj1j5a7q328e4ohrgs7e2loe0: Rmdir: contains file: "n01jpl9202nn9ec1rb75h0f1c4" 2025/04/04 06:02:27 DEBUG : rclone-sync-test-include: Failed to Rmdir: directory not empty 2025/04/04 06:02:27 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-suxokod1xame': failed to delete 1 directories 2025/04/04 06:02:27 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-suxokod1xame'", Local "Local file system at /tmp/rclone1679136044", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-suxokod1xame'", Local "Local file system at /tmp/rclone1679136044", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-suxokod1xame'", Local "Local file system at /tmp/rclone1679136044", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-suxokod1xame'", Local "Local file system at /tmp/rclone1679136044", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-suxokod1xame'", Local "Local file system at /tmp/rclone1679136044", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-suxokod1xame'", Local "Local file system at /tmp/rclone1679136044", Modify Window "1ms" 2025/04/04 06:02:29 DEBUG : Added delayed dir = "rclone-sync-test-include", newDst= 2025/04/04 06:02:29 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-suxokod1xame/rclone-sync-test-include/layer2': Waiting for checks to finish 2025/04/04 06:02:29 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-suxokod1xame/rclone-sync-test-include/layer2': Waiting for transfers to finish 2025/04/04 06:02:29 DEBUG : Waiting for deletions to finish 2025/04/04 06:02:29 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-suxokod1xame'", Local "Local file system at /tmp/rclone1679136044", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-suxokod1xame'", Local "Local file system at /tmp/rclone1679136044", Modify Window "1ms" 2025/04/04 06:02:31 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-suxokod1xame': Waiting for checks to finish 2025/04/04 06:02:31 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-suxokod1xame': Waiting for transfers to finish 2025/04/04 06:02:31 DEBUG : Waiting for deletions to finish 2025/04/04 06:02:31 INFO : rclone-sync-test-include: Removing directory 2025/04/04 06:02:32 DEBUG : khf2vlblvnbf9ftevqm0htmss73hj1j5a7q328e4ohrgs7e2loe0: Rmdir: contains file: "n01jpl9202nn9ec1rb75h0f1c4" 2025/04/04 06:02:32 DEBUG : rclone-sync-test-include: Failed to Rmdir: directory not empty 2025/04/04 06:02:32 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-suxokod1xame': failed to delete 1 directories 2025/04/04 06:02:32 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-suxokod1xame'", Local "Local file system at /tmp/rclone1679136044", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-suxokod1xame'", Local "Local file system at /tmp/rclone1679136044", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-suxokod1xame'", Local "Local file system at /tmp/rclone1679136044", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-suxokod1xame'", Local "Local file system at /tmp/rclone1679136044", Modify Window "1ms" 2025/04/04 06:02:34 DEBUG : Added delayed dir = "rclone-sync-test-include", newDst= 2025/04/04 06:02:34 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-suxokod1xame/rclone-sync-test-ignore-file': Waiting for checks to finish 2025/04/04 06:02:34 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-suxokod1xame/rclone-sync-test-ignore-file': Waiting for transfers to finish 2025/04/04 06:02:34 DEBUG : Waiting for deletions to finish 2025/04/04 06:02:34 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-suxokod1xame'", Local "Local file system at /tmp/rclone1679136044", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-suxokod1xame'", Local "Local file system at /tmp/rclone1679136044", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-suxokod1xame'", Local "Local file system at /tmp/rclone1679136044", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-suxokod1xame'", Local "Local file system at /tmp/rclone1679136044", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-suxokod1xame'", Local "Local file system at /tmp/rclone1679136044", Modify Window "1ms" 2025/04/04 06:02:36 DEBUG : khf2vlblvnbf9ftevqm0htmss73hj1j5a7q328e4ohrgs7e2loe0: Rmdir: contains trashed file: "n01jpl9202nn9ec1rb75h0f1c4" 2025/04/04 06:02:37 DEBUG : kmf11jujl9uha3tjganvgpkn45bu778hb5vb5riug1c26b38k7sg: Rmdir: contains trashed file: "i0t74httmdlljg425j6tg570d8" --- PASS: TestSyncOverlapWithFilter (31.97s) === RUN TestSyncCompareDest run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-suxokod1xame'", Local "Local file system at /tmp/rclone1679136044", Modify Window "1ms" 2025/04/04 06:02:46 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-suxokod1xame/dst" 2025/04/04 06:02:46 DEBUG : Creating backend with remote "TestDrive:crypt/5k4c2md6mve4em7b73jkmidja3fb2nbopd8em58nbtfjmjegpu8g/31u3jie661vd5p8j7rtc3hgbh0" 2025/04/04 06:02:47 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-suxokod1xame/CompareDest" 2025/04/04 06:02:47 DEBUG : Creating backend with remote "TestDrive:crypt/5k4c2md6mve4em7b73jkmidja3fb2nbopd8em58nbtfjmjegpu8g/gveqi14airsml4bgu7krj116o8" 2025/04/04 06:02:49 DEBUG : one: Need to transfer - File not found at Destination 2025/04/04 06:02:49 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-suxokod1xame/dst': Waiting for checks to finish 2025/04/04 06:02:49 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-suxokod1xame/dst': Waiting for transfers to finish 2025/04/04 06:02:51 DEBUG : one: md5 = 8b4bc407ae3a1849ea6d96ab1696a6df OK 2025/04/04 06:02:51 INFO : one: Copied (new) 2025/04/04 06:02:51 DEBUG : Waiting for deletions to finish 2025/04/04 06:02:52 DEBUG : one: Sizes differ (src 5 vs dst 3) 2025/04/04 06:02:52 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-suxokod1xame/dst': Waiting for checks to finish 2025/04/04 06:02:53 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-suxokod1xame/dst': Waiting for transfers to finish 2025/04/04 06:02:54 DEBUG : one: md5 = 80ef4d25c4641d899754a748475266f5 OK 2025/04/04 06:02:54 INFO : one: Copied (replaced existing) 2025/04/04 06:02:54 DEBUG : Waiting for deletions to finish 2025/04/04 06:02:56 DEBUG : dst/one: md5 = 104062a28759ce8ac009ce3b99a052b2 OK 2025/04/04 06:02:58 DEBUG : CompareDest/one: md5 = 6115617535231291608213c5a3833c26 OK 2025/04/04 06:02:58 DEBUG : one: Sizes differ (src 5 vs dst 3) 2025/04/04 06:02:58 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-suxokod1xame/dst': Waiting for checks to finish 2025/04/04 06:02:59 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/04/04 06:02:59 DEBUG : one: Destination found in --compare-dest, skipping 2025/04/04 06:02:59 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-suxokod1xame/dst': Waiting for transfers to finish 2025/04/04 06:02:59 DEBUG : Waiting for deletions to finish 2025/04/04 06:02:59 INFO : There was nothing to transfer 2025/04/04 06:03:01 DEBUG : CompareDest/two: md5 = a9e1448a951338f685cca7fcb19df259 OK 2025/04/04 06:03:02 DEBUG : two: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/04/04 06:03:02 DEBUG : two: Destination found in --compare-dest, skipping 2025/04/04 06:03:02 DEBUG : one: Sizes differ (src 5 vs dst 3) 2025/04/04 06:03:02 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-suxokod1xame/dst': Waiting for checks to finish 2025/04/04 06:03:02 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/04/04 06:03:02 DEBUG : one: Destination found in --compare-dest, skipping 2025/04/04 06:03:02 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-suxokod1xame/dst': Waiting for transfers to finish 2025/04/04 06:03:02 DEBUG : Waiting for deletions to finish 2025/04/04 06:03:02 INFO : There was nothing to transfer 2025/04/04 06:03:03 DEBUG : two: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/04/04 06:03:03 DEBUG : two: Destination found in --compare-dest, skipping 2025/04/04 06:03:03 DEBUG : one: Sizes differ (src 5 vs dst 3) 2025/04/04 06:03:03 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-suxokod1xame/dst': Waiting for checks to finish 2025/04/04 06:03:03 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/04/04 06:03:03 DEBUG : one: Destination found in --compare-dest, skipping 2025/04/04 06:03:03 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-suxokod1xame/dst': Waiting for transfers to finish 2025/04/04 06:03:03 DEBUG : Waiting for deletions to finish 2025/04/04 06:03:03 INFO : There was nothing to transfer sync_test.go:2175: No hash on uploaded file so skipping compare timestamp test 2025/04/04 06:03:05 DEBUG : two: Sizes differ (src 5 vs dst 3) 2025/04/04 06:03:05 DEBUG : two: Need to transfer - File not found at Destination 2025/04/04 06:03:05 DEBUG : one: Sizes differ (src 5 vs dst 3) 2025/04/04 06:03:05 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-suxokod1xame/dst': Waiting for checks to finish 2025/04/04 06:03:05 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/04/04 06:03:05 DEBUG : one: Destination found in --compare-dest, skipping 2025/04/04 06:03:05 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-suxokod1xame/dst': Waiting for transfers to finish 2025/04/04 06:03:06 DEBUG : two: md5 = 1a4b4cae84c0ed75c399326865005a5a OK 2025/04/04 06:03:06 INFO : two: Copied (new) 2025/04/04 06:03:06 DEBUG : Waiting for deletions to finish 2025/04/04 06:03:09 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k" 2025/04/04 06:03:09 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" 2025/04/04 06:03:09 DEBUG : gveqi14airsml4bgu7krj116o8: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" 2025/04/04 06:03:09 DEBUG : gveqi14airsml4bgu7krj116o8: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k" --- PASS: TestSyncCompareDest (24.36s) === RUN TestSyncMultipleCompareDest run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-suxokod1xame'", Local "Local file system at /tmp/rclone1679136044", Modify Window "1ms" 2025/04/04 06:03:12 DEBUG : pre-dest1/1: md5 = 1254d39a2a6263633fc4c93708207ab1 OK 2025/04/04 06:03:14 DEBUG : pre-dest2/2: md5 = c5e9f8fd8e2e1b6265d547c937533688 OK 2025/04/04 06:03:15 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-suxokod1xame/dest" 2025/04/04 06:03:15 DEBUG : Creating backend with remote "TestDrive:crypt/5k4c2md6mve4em7b73jkmidja3fb2nbopd8em58nbtfjmjegpu8g/rg03c1jvnehrrc617i0lnqjddc" 2025/04/04 06:03:16 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-suxokod1xame/pre-dest1" 2025/04/04 06:03:16 DEBUG : Creating backend with remote "TestDrive:crypt/5k4c2md6mve4em7b73jkmidja3fb2nbopd8em58nbtfjmjegpu8g/bbnblvh6k061ssopqrp18kd7gc" 2025/04/04 06:03:17 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-suxokod1xame/pre-dest2" 2025/04/04 06:03:17 DEBUG : Creating backend with remote "TestDrive:crypt/5k4c2md6mve4em7b73jkmidja3fb2nbopd8em58nbtfjmjegpu8g/dgicm1h6b5ejvlltm8eeif0bnk" 2025/04/04 06:03:18 DEBUG : 1: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/04 06:03:18 DEBUG : 1: Destination found in --compare-dest, skipping 2025/04/04 06:03:19 DEBUG : 2: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/04 06:03:19 DEBUG : 2: Destination found in --compare-dest, skipping 2025/04/04 06:03:19 DEBUG : 3: Need to transfer - File not found at Destination 2025/04/04 06:03:19 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-suxokod1xame/dest': Waiting for checks to finish 2025/04/04 06:03:19 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-suxokod1xame/dest': Waiting for transfers to finish 2025/04/04 06:03:21 DEBUG : 3: md5 = d67af3c12ef5123b56097289f3b3bd40 OK 2025/04/04 06:03:21 INFO : 3: Copied (new) 2025/04/04 06:03:21 DEBUG : Waiting for deletions to finish 2025/04/04 06:03:24 DEBUG : dgicm1h6b5ejvlltm8eeif0bnk: Rmdir: contains trashed file: "1ghu8geql9vrl726n32nrf65bc" 2025/04/04 06:03:25 DEBUG : bbnblvh6k061ssopqrp18kd7gc: Rmdir: contains trashed file: "skbfko3oil7es0lj68ob574sro" 2025/04/04 06:03:26 DEBUG : rg03c1jvnehrrc617i0lnqjddc: Rmdir: contains trashed file: "g072p7hmjchlnj0gibe64c1epg" --- PASS: TestSyncMultipleCompareDest (16.24s) === RUN TestSyncCopyDest run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-suxokod1xame'", Local "Local file system at /tmp/rclone1679136044", Modify Window "1ms" 2025/04/04 06:03:26 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-suxokod1xame/dst" 2025/04/04 06:03:26 DEBUG : Creating backend with remote "TestDrive:crypt/5k4c2md6mve4em7b73jkmidja3fb2nbopd8em58nbtfjmjegpu8g/31u3jie661vd5p8j7rtc3hgbh0" 2025/04/04 06:03:28 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-suxokod1xame/CopyDest" 2025/04/04 06:03:28 DEBUG : Creating backend with remote "TestDrive:crypt/5k4c2md6mve4em7b73jkmidja3fb2nbopd8em58nbtfjmjegpu8g/d09o6po3f7bm6ce32vdgs8h9ls" 2025/04/04 06:03:30 DEBUG : one: Need to transfer - File not found at Destination 2025/04/04 06:03:30 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-suxokod1xame/dst': Waiting for checks to finish 2025/04/04 06:03:30 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-suxokod1xame/dst': Waiting for transfers to finish 2025/04/04 06:03:32 DEBUG : one: md5 = 3ba8993bcab6f43af5abf3f1c4052b8e OK 2025/04/04 06:03:32 INFO : one: Copied (new) 2025/04/04 06:03:32 DEBUG : Waiting for deletions to finish 2025/04/04 06:03:33 DEBUG : one: Sizes differ (src 5 vs dst 3) 2025/04/04 06:03:33 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-suxokod1xame/dst': Waiting for checks to finish 2025/04/04 06:03:33 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-suxokod1xame/dst': Waiting for transfers to finish 2025/04/04 06:03:34 DEBUG : one: md5 = 7b7efb920c2e734afed96c64ca8f7823 OK 2025/04/04 06:03:34 INFO : one: Copied (replaced existing) 2025/04/04 06:03:34 DEBUG : Waiting for deletions to finish 2025/04/04 06:03:36 DEBUG : dst/one: md5 = a40e063d282be8715a8436c756e254fd OK 2025/04/04 06:03:38 DEBUG : CopyDest/one: md5 = 5070a84b689e5b24462ab216189c0e35 OK 2025/04/04 06:03:39 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-suxokod1xame/BackupDir" 2025/04/04 06:03:39 DEBUG : Creating backend with remote "TestDrive:crypt/5k4c2md6mve4em7b73jkmidja3fb2nbopd8em58nbtfjmjegpu8g/s6dbk3lfi7c9kfvo6j7bla9m0g" 2025/04/04 06:03:40 DEBUG : one: Sizes differ (src 5 vs dst 3) 2025/04/04 06:03:40 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-suxokod1xame/dst': Waiting for checks to finish 2025/04/04 06:03:41 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/04/04 06:03:41 DEBUG : one: Sizes differ (src 5 vs dst 3) 2025/04/04 06:03:43 INFO : one: Moved (server-side) 2025/04/04 06:03:44 INFO : one: Copied (server-side copy) 2025/04/04 06:03:44 DEBUG : one: Destination found in --copy-dest, using server-side copy 2025/04/04 06:03:44 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-suxokod1xame/dst': Waiting for transfers to finish 2025/04/04 06:03:44 DEBUG : Waiting for deletions to finish 2025/04/04 06:03:45 DEBUG : CopyDest/two: md5 = fb5551cc0d6a64d8b93fb5084cee65a4 OK 2025/04/04 06:03:47 DEBUG : two: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/04/04 06:03:48 INFO : two: Copied (server-side copy) 2025/04/04 06:03:48 DEBUG : two: Destination found in --copy-dest, using server-side copy 2025/04/04 06:03:48 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/04/04 06:03:48 DEBUG : one: Unchanged skipping 2025/04/04 06:03:48 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-suxokod1xame/dst': Waiting for checks to finish 2025/04/04 06:03:48 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-suxokod1xame/dst': Waiting for transfers to finish 2025/04/04 06:03:48 DEBUG : Waiting for deletions to finish 2025/04/04 06:03:48 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/04/04 06:03:48 DEBUG : one: Unchanged skipping 2025/04/04 06:03:48 DEBUG : two: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/04/04 06:03:48 DEBUG : two: Unchanged skipping 2025/04/04 06:03:48 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-suxokod1xame/dst': Waiting for checks to finish 2025/04/04 06:03:48 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-suxokod1xame/dst': Waiting for transfers to finish 2025/04/04 06:03:48 DEBUG : Waiting for deletions to finish 2025/04/04 06:03:48 INFO : There was nothing to transfer 2025/04/04 06:03:50 DEBUG : CopyDest/three: md5 = 5e74c860dd9e65dad10eae056ecbc57c OK 2025/04/04 06:03:51 DEBUG : three: Sizes differ (src 7 vs dst 5) 2025/04/04 06:03:51 DEBUG : three: Destination not found in --copy-dest 2025/04/04 06:03:51 DEBUG : three: Need to transfer - File not found at Destination 2025/04/04 06:03:51 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/04/04 06:03:51 DEBUG : one: Unchanged skipping 2025/04/04 06:03:51 DEBUG : two: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/04/04 06:03:51 DEBUG : two: Unchanged skipping 2025/04/04 06:03:51 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-suxokod1xame/dst': Waiting for checks to finish 2025/04/04 06:03:51 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-suxokod1xame/dst': Waiting for transfers to finish 2025/04/04 06:03:52 DEBUG : three: md5 = 1919709b1d9946be55cc4d292c0e94c2 OK 2025/04/04 06:03:52 INFO : three: Copied (new) 2025/04/04 06:03:52 DEBUG : Waiting for deletions to finish 2025/04/04 06:03:57 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "b6jdmn2b1adrhc8vikh7edr9os" 2025/04/04 06:03:57 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k" 2025/04/04 06:03:57 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" 2025/04/04 06:03:57 DEBUG : d09o6po3f7bm6ce32vdgs8h9ls: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" 2025/04/04 06:03:57 DEBUG : d09o6po3f7bm6ce32vdgs8h9ls: Rmdir: contains trashed file: "b6jdmn2b1adrhc8vikh7edr9os" 2025/04/04 06:03:57 DEBUG : d09o6po3f7bm6ce32vdgs8h9ls: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k" 2025/04/04 06:03:58 DEBUG : s6dbk3lfi7c9kfvo6j7bla9m0g: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" --- PASS: TestSyncCopyDest (32.40s) === RUN TestSyncBackupDir run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-suxokod1xame'", Local "Local file system at /tmp/rclone1679136044", Modify Window "1ms" 2025/04/04 06:04:01 DEBUG : dst/one: md5 = e945423162481ff5314eb048f0de42c2 OK 2025/04/04 06:04:02 DEBUG : dst/two: md5 = ed697165746fd81b99e3b6091f7ee608 OK 2025/04/04 06:04:03 DEBUG : dst/three.txt: md5 = 03216157e683e3d8c76c68422fa9ff11 OK 2025/04/04 06:04:04 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-suxokod1xame/dst" 2025/04/04 06:04:04 DEBUG : Creating backend with remote "TestDrive:crypt/5k4c2md6mve4em7b73jkmidja3fb2nbopd8em58nbtfjmjegpu8g/31u3jie661vd5p8j7rtc3hgbh0" 2025/04/04 06:04:05 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-suxokod1xame/backup" 2025/04/04 06:04:05 DEBUG : Creating backend with remote "TestDrive:crypt/5k4c2md6mve4em7b73jkmidja3fb2nbopd8em58nbtfjmjegpu8g/1nrff024r7pq65ecp72fc28jb0" 2025/04/04 06:04:06 DEBUG : one: Sizes differ (src 4 vs dst 3) 2025/04/04 06:04:06 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/04 06:04:06 DEBUG : two: Unchanged skipping 2025/04/04 06:04:06 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-suxokod1xame/dst': Waiting for checks to finish 2025/04/04 06:04:08 INFO : one: Moved (server-side) 2025/04/04 06:04:08 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-suxokod1xame/dst': Waiting for transfers to finish 2025/04/04 06:04:09 DEBUG : one: md5 = 8867b423067fec480b3115dbb80f8b58 OK 2025/04/04 06:04:09 INFO : one: Copied (new) 2025/04/04 06:04:09 DEBUG : Waiting for deletions to finish 2025/04/04 06:04:10 INFO : three.txt: Moved (server-side) 2025/04/04 06:04:10 INFO : three.txt: Moved into backup dir 2025/04/04 06:04:12 DEBUG : dst/three.txt: md5 = afbe911be89b7130b04a5db1a69c9edf OK 2025/04/04 06:04:13 DEBUG : one: Sizes differ (src 5 vs dst 4) 2025/04/04 06:04:13 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/04 06:04:13 DEBUG : two: Unchanged skipping 2025/04/04 06:04:13 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-suxokod1xame/dst': Waiting for checks to finish 2025/04/04 06:04:14 INFO : one: Deleted 2025/04/04 06:04:14 INFO : one: Moved (server-side) 2025/04/04 06:04:14 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-suxokod1xame/dst': Waiting for transfers to finish 2025/04/04 06:04:15 DEBUG : one: md5 = 675104deb8805a059f549ae4b54e9832 OK 2025/04/04 06:04:15 INFO : one: Copied (new) 2025/04/04 06:04:15 DEBUG : Waiting for deletions to finish 2025/04/04 06:04:16 INFO : three.txt: Deleted 2025/04/04 06:04:17 INFO : three.txt: Moved (server-side) 2025/04/04 06:04:17 INFO : three.txt: Moved into backup dir 2025/04/04 06:04:20 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" 2025/04/04 06:04:20 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k" 2025/04/04 06:04:20 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "tr2hj63d80ftlmvm6a952snjcc" 2025/04/04 06:04:20 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" 2025/04/04 06:04:20 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" 2025/04/04 06:04:20 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "tr2hj63d80ftlmvm6a952snjcc" --- PASS: TestSyncBackupDir (22.37s) === RUN TestSyncBackupDirWithSuffix run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-suxokod1xame'", Local "Local file system at /tmp/rclone1679136044", Modify Window "1ms" 2025/04/04 06:04:23 DEBUG : dst/one: md5 = e68b9be4542c5bf443daa419fcb5f28a OK 2025/04/04 06:04:25 DEBUG : dst/two: md5 = 3fbb327c24fe7452f5587e2c6d5f665b OK 2025/04/04 06:04:26 DEBUG : dst/three.txt: md5 = 50d74c7e57d59d9a3dbf0d1c22858b4b OK 2025/04/04 06:04:26 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-suxokod1xame/dst" 2025/04/04 06:04:26 DEBUG : Creating backend with remote "TestDrive:crypt/5k4c2md6mve4em7b73jkmidja3fb2nbopd8em58nbtfjmjegpu8g/31u3jie661vd5p8j7rtc3hgbh0" 2025/04/04 06:04:27 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-suxokod1xame/backup" 2025/04/04 06:04:27 DEBUG : Creating backend with remote "TestDrive:crypt/5k4c2md6mve4em7b73jkmidja3fb2nbopd8em58nbtfjmjegpu8g/1nrff024r7pq65ecp72fc28jb0" 2025/04/04 06:04:29 DEBUG : one: Sizes differ (src 4 vs dst 3) 2025/04/04 06:04:29 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/04 06:04:29 DEBUG : two: Unchanged skipping 2025/04/04 06:04:29 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-suxokod1xame/dst': Waiting for checks to finish 2025/04/04 06:04:31 INFO : one: Moved (server-side) to: one.bak 2025/04/04 06:04:31 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-suxokod1xame/dst': Waiting for transfers to finish 2025/04/04 06:04:32 DEBUG : one: md5 = b1efe0de7a2d4f5cad29274514eee926 OK 2025/04/04 06:04:32 INFO : one: Copied (new) 2025/04/04 06:04:32 DEBUG : Waiting for deletions to finish 2025/04/04 06:04:33 INFO : three.txt: Moved (server-side) to: three.txt.bak 2025/04/04 06:04:33 INFO : three.txt: Moved into backup dir 2025/04/04 06:04:35 DEBUG : dst/three.txt: md5 = acdd7864d3432245ce2c17f06d1d57c7 OK 2025/04/04 06:04:35 DEBUG : one: Sizes differ (src 5 vs dst 4) 2025/04/04 06:04:35 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/04 06:04:35 DEBUG : two: Unchanged skipping 2025/04/04 06:04:35 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-suxokod1xame/dst': Waiting for checks to finish 2025/04/04 06:04:36 INFO : one.bak: Deleted 2025/04/04 06:04:37 INFO : one: Moved (server-side) to: one.bak 2025/04/04 06:04:37 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-suxokod1xame/dst': Waiting for transfers to finish 2025/04/04 06:04:38 DEBUG : one: md5 = 88e232e1b869d29e41929bb262fc8c68 OK 2025/04/04 06:04:38 INFO : one: Copied (new) 2025/04/04 06:04:38 DEBUG : Waiting for deletions to finish 2025/04/04 06:04:39 INFO : three.txt.bak: Deleted 2025/04/04 06:04:39 INFO : three.txt: Moved (server-side) to: three.txt.bak 2025/04/04 06:04:39 INFO : three.txt: Moved into backup dir 2025/04/04 06:04:42 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" 2025/04/04 06:04:42 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k" 2025/04/04 06:04:43 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "sk91qgsqfn0r271r2ehsaoc20c" 2025/04/04 06:04:43 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "qltcak2uaegtmcoa8vijdppbp8" 2025/04/04 06:04:43 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "sk91qgsqfn0r271r2ehsaoc20c" 2025/04/04 06:04:43 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "qltcak2uaegtmcoa8vijdppbp8" --- PASS: TestSyncBackupDirWithSuffix (22.76s) === RUN TestSyncBackupDirWithSuffixKeepExtension run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-suxokod1xame'", Local "Local file system at /tmp/rclone1679136044", Modify Window "1ms" 2025/04/04 06:04:46 DEBUG : dst/one: md5 = a2746447c3dc1f4ff55d6227697ff1be OK 2025/04/04 06:04:47 DEBUG : dst/two: md5 = 4e72d7cb515175f1a85829eaa553d4ba OK 2025/04/04 06:04:49 DEBUG : dst/three.txt: md5 = 110b42313aa723341e865122e4e5e4b5 OK 2025/04/04 06:04:49 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-suxokod1xame/dst" 2025/04/04 06:04:49 DEBUG : Creating backend with remote "TestDrive:crypt/5k4c2md6mve4em7b73jkmidja3fb2nbopd8em58nbtfjmjegpu8g/31u3jie661vd5p8j7rtc3hgbh0" 2025/04/04 06:04:50 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-suxokod1xame/backup" 2025/04/04 06:04:50 DEBUG : Creating backend with remote "TestDrive:crypt/5k4c2md6mve4em7b73jkmidja3fb2nbopd8em58nbtfjmjegpu8g/1nrff024r7pq65ecp72fc28jb0" 2025/04/04 06:04:52 DEBUG : one: Sizes differ (src 4 vs dst 3) 2025/04/04 06:04:52 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-suxokod1xame/dst': Waiting for checks to finish 2025/04/04 06:04:52 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/04 06:04:52 DEBUG : two: Unchanged skipping 2025/04/04 06:04:53 INFO : one: Moved (server-side) to: one-2019-01-01 2025/04/04 06:04:53 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-suxokod1xame/dst': Waiting for transfers to finish 2025/04/04 06:04:55 DEBUG : one: md5 = 1b71d15bd121db8f14cab87f899043c8 OK 2025/04/04 06:04:55 INFO : one: Copied (new) 2025/04/04 06:04:55 DEBUG : Waiting for deletions to finish 2025/04/04 06:04:56 INFO : three.txt: Moved (server-side) to: three-2019-01-01.txt 2025/04/04 06:04:56 INFO : three.txt: Moved into backup dir 2025/04/04 06:04:57 DEBUG : dst/three.txt: md5 = 5d581ca332803b4d61b1b7387a742828 OK 2025/04/04 06:04:58 DEBUG : one: Sizes differ (src 5 vs dst 4) 2025/04/04 06:04:58 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/04 06:04:58 DEBUG : two: Unchanged skipping 2025/04/04 06:04:58 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-suxokod1xame/dst': Waiting for checks to finish 2025/04/04 06:04:59 INFO : one-2019-01-01: Deleted 2025/04/04 06:04:59 INFO : one: Moved (server-side) to: one-2019-01-01 2025/04/04 06:04:59 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-suxokod1xame/dst': Waiting for transfers to finish 2025/04/04 06:05:01 DEBUG : one: md5 = 056174ce8f28da23885842f618712790 OK 2025/04/04 06:05:01 INFO : one: Copied (new) 2025/04/04 06:05:01 DEBUG : Waiting for deletions to finish 2025/04/04 06:05:02 INFO : three-2019-01-01.txt: Deleted 2025/04/04 06:05:02 INFO : three.txt: Moved (server-side) to: three-2019-01-01.txt 2025/04/04 06:05:02 INFO : three.txt: Moved into backup dir 2025/04/04 06:05:05 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" 2025/04/04 06:05:05 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k" 2025/04/04 06:05:06 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "qtq2f6qq4lgpsmj88vb7147qje3prudmtfdtr2342fth58vo9a50" 2025/04/04 06:05:06 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "jcjl1bv3ep0v8kt35lqql1co90" 2025/04/04 06:05:06 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "qtq2f6qq4lgpsmj88vb7147qje3prudmtfdtr2342fth58vo9a50" 2025/04/04 06:05:06 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "jcjl1bv3ep0v8kt35lqql1co90" --- PASS: TestSyncBackupDirWithSuffixKeepExtension (22.65s) === RUN TestSyncBackupDirSuffixOnly run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-suxokod1xame'", Local "Local file system at /tmp/rclone1679136044", Modify Window "1ms" 2025/04/04 06:05:09 DEBUG : dst/one: md5 = 8196104c05db0fa48fb75345b349cc19 OK 2025/04/04 06:05:10 DEBUG : dst/two: md5 = 3417c920807bb13ef14d6ecfa3a7e555 OK 2025/04/04 06:05:11 DEBUG : dst/three.txt: md5 = 0aff578a5480fa463eaf069e5ebc9988 OK 2025/04/04 06:05:12 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-suxokod1xame/dst" 2025/04/04 06:05:12 DEBUG : Creating backend with remote "TestDrive:crypt/5k4c2md6mve4em7b73jkmidja3fb2nbopd8em58nbtfjmjegpu8g/31u3jie661vd5p8j7rtc3hgbh0" 2025/04/04 06:05:13 DEBUG : one: Sizes differ (src 4 vs dst 3) 2025/04/04 06:05:13 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/04 06:05:13 DEBUG : two: Unchanged skipping 2025/04/04 06:05:13 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-suxokod1xame/dst': Waiting for checks to finish 2025/04/04 06:05:13 INFO : one: Moved (server-side) to: one.bak 2025/04/04 06:05:13 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-suxokod1xame/dst': Waiting for transfers to finish 2025/04/04 06:05:15 DEBUG : one: md5 = 835599bcae9e2bdbdd1995e9b0cf1e20 OK 2025/04/04 06:05:15 INFO : one: Copied (new) 2025/04/04 06:05:15 DEBUG : Waiting for deletions to finish 2025/04/04 06:05:15 INFO : three.txt: Moved (server-side) to: three.txt.bak 2025/04/04 06:05:15 INFO : three.txt: Moved into backup dir 2025/04/04 06:05:17 DEBUG : dst/three.txt: md5 = 5064c1051fd957792bc06117288d5906 OK 2025/04/04 06:05:18 DEBUG : one.bak: Excluded (Path Filter) 2025/04/04 06:05:18 DEBUG : three.txt.bak: Excluded (Path Filter) 2025/04/04 06:05:18 DEBUG : one: Sizes differ (src 5 vs dst 4) 2025/04/04 06:05:18 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/04 06:05:18 DEBUG : two: Unchanged skipping 2025/04/04 06:05:18 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-suxokod1xame/dst': Waiting for checks to finish 2025/04/04 06:05:19 INFO : one.bak: Deleted 2025/04/04 06:05:19 INFO : one: Moved (server-side) to: one.bak 2025/04/04 06:05:19 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-suxokod1xame/dst': Waiting for transfers to finish 2025/04/04 06:05:21 DEBUG : one: md5 = 8e39a7cc7586811af913a2f5d9705523 OK 2025/04/04 06:05:21 INFO : one: Copied (new) 2025/04/04 06:05:21 DEBUG : Waiting for deletions to finish 2025/04/04 06:05:21 INFO : three.txt.bak: Deleted 2025/04/04 06:05:22 INFO : three.txt: Moved (server-side) to: three.txt.bak 2025/04/04 06:05:22 INFO : three.txt: Moved into backup dir 2025/04/04 06:05:25 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" 2025/04/04 06:05:25 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "qltcak2uaegtmcoa8vijdppbp8" 2025/04/04 06:05:25 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "sk91qgsqfn0r271r2ehsaoc20c" 2025/04/04 06:05:25 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "qltcak2uaegtmcoa8vijdppbp8" 2025/04/04 06:05:25 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "sk91qgsqfn0r271r2ehsaoc20c" 2025/04/04 06:05:25 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k" --- PASS: TestSyncBackupDirSuffixOnly (19.26s) === RUN TestSyncSuffix run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-suxokod1xame'", Local "Local file system at /tmp/rclone1679136044", Modify Window "1ms" 2025/04/04 06:05:28 DEBUG : dst/one: md5 = b649278818101ff4d51f07c49d70b592 OK 2025/04/04 06:05:29 DEBUG : dst/two: md5 = 2362bf8fe90229e54e28535be4945636 OK 2025/04/04 06:05:31 DEBUG : dst/three.txt: md5 = abaf2c239fb023dfd08dc144a156d258 OK 2025/04/04 06:05:31 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-suxokod1xame/dst" 2025/04/04 06:05:31 DEBUG : Creating backend with remote "TestDrive:crypt/5k4c2md6mve4em7b73jkmidja3fb2nbopd8em58nbtfjmjegpu8g/31u3jie661vd5p8j7rtc3hgbh0" 2025/04/04 06:05:32 DEBUG : one: Sizes differ (src 4 vs dst 3) 2025/04/04 06:05:33 INFO : one: Moved (server-side) to: one.bak 2025/04/04 06:05:34 DEBUG : one: md5 = 0609bf2689c4c7fbe8aeba55fa3f411c OK 2025/04/04 06:05:34 INFO : one: Copied (new) 2025/04/04 06:05:35 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/04 06:05:35 DEBUG : two: Unchanged skipping 2025/04/04 06:05:35 DEBUG : three.txt: Sizes differ (src 6 vs dst 5) 2025/04/04 06:05:36 INFO : three.txt: Moved (server-side) to: three.txt.bak 2025/04/04 06:05:37 DEBUG : three.txt: md5 = ea5e81f8f21ed046a852f474966eb73a OK 2025/04/04 06:05:37 INFO : three.txt: Copied (new) 2025/04/04 06:05:38 DEBUG : one: Sizes differ (src 5 vs dst 4) 2025/04/04 06:05:39 INFO : one.bak: Deleted 2025/04/04 06:05:39 INFO : one: Moved (server-side) to: one.bak 2025/04/04 06:05:41 DEBUG : one: md5 = c41bda4d1f5da9d5fbadac86b51eb5cf OK 2025/04/04 06:05:41 INFO : one: Copied (new) 2025/04/04 06:05:41 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/04 06:05:41 DEBUG : two: Unchanged skipping 2025/04/04 06:05:41 DEBUG : three.txt: Sizes differ (src 19 vs dst 6) 2025/04/04 06:05:42 INFO : three.txt.bak: Deleted 2025/04/04 06:05:43 INFO : three.txt: Moved (server-side) to: three.txt.bak 2025/04/04 06:05:44 DEBUG : three.txt: md5 = 85da96de3764a3c3f7b232fcb17746a8 OK 2025/04/04 06:05:44 INFO : three.txt: Copied (new) 2025/04/04 06:05:48 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "tr2hj63d80ftlmvm6a952snjcc" 2025/04/04 06:05:48 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" 2025/04/04 06:05:48 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "qltcak2uaegtmcoa8vijdppbp8" 2025/04/04 06:05:48 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k" 2025/04/04 06:05:48 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "sk91qgsqfn0r271r2ehsaoc20c" 2025/04/04 06:05:48 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "sk91qgsqfn0r271r2ehsaoc20c" 2025/04/04 06:05:48 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "qltcak2uaegtmcoa8vijdppbp8" --- PASS: TestSyncSuffix (22.77s) === RUN TestSyncSuffixKeepExtension run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-suxokod1xame'", Local "Local file system at /tmp/rclone1679136044", Modify Window "1ms" 2025/04/04 06:05:50 DEBUG : dst/one: md5 = cdbc12eb9f96f7f8334fd7a0a440eaeb OK 2025/04/04 06:05:52 DEBUG : dst/two: md5 = 1939a9671963893a9bca16f6863e8768 OK 2025/04/04 06:05:53 DEBUG : dst/three.txt: md5 = a5f695402e43d279b0c001ed7b48d516 OK 2025/04/04 06:05:54 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-suxokod1xame/dst" 2025/04/04 06:05:54 DEBUG : Creating backend with remote "TestDrive:crypt/5k4c2md6mve4em7b73jkmidja3fb2nbopd8em58nbtfjmjegpu8g/31u3jie661vd5p8j7rtc3hgbh0" 2025/04/04 06:05:55 DEBUG : one: Sizes differ (src 4 vs dst 3) 2025/04/04 06:05:56 INFO : one: Moved (server-side) to: one-2019-01-01 2025/04/04 06:05:57 DEBUG : one: md5 = 3acabfd37b66d0f7b214008de628173b OK 2025/04/04 06:05:57 INFO : one: Copied (new) 2025/04/04 06:05:57 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/04 06:05:57 DEBUG : two: Unchanged skipping 2025/04/04 06:05:57 DEBUG : three.txt: Sizes differ (src 6 vs dst 5) 2025/04/04 06:05:58 INFO : three.txt: Moved (server-side) to: three-2019-01-01.txt 2025/04/04 06:06:00 DEBUG : three.txt: md5 = 0117a9c979f4c3337fdd1d28f6806645 OK 2025/04/04 06:06:00 INFO : three.txt: Copied (new) 2025/04/04 06:06:01 DEBUG : one: Sizes differ (src 5 vs dst 4) 2025/04/04 06:06:01 INFO : one-2019-01-01: Deleted 2025/04/04 06:06:02 INFO : one: Moved (server-side) to: one-2019-01-01 2025/04/04 06:06:03 DEBUG : one: md5 = 9ae642ec2af278677d5bbc87096b8414 OK 2025/04/04 06:06:03 INFO : one: Copied (new) 2025/04/04 06:06:03 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/04 06:06:03 DEBUG : two: Unchanged skipping 2025/04/04 06:06:04 DEBUG : three.txt: Sizes differ (src 19 vs dst 6) 2025/04/04 06:06:04 INFO : three-2019-01-01.txt: Deleted 2025/04/04 06:06:05 INFO : three.txt: Moved (server-side) to: three-2019-01-01.txt 2025/04/04 06:06:06 DEBUG : three.txt: md5 = a992820bdcbdd6be9c23ea703b0f8bdc OK 2025/04/04 06:06:06 INFO : three.txt: Copied (new) 2025/04/04 06:06:10 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "tr2hj63d80ftlmvm6a952snjcc" 2025/04/04 06:06:10 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" 2025/04/04 06:06:10 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "jcjl1bv3ep0v8kt35lqql1co90" 2025/04/04 06:06:10 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "jcjl1bv3ep0v8kt35lqql1co90" 2025/04/04 06:06:10 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "qtq2f6qq4lgpsmj88vb7147qje3prudmtfdtr2342fth58vo9a50" 2025/04/04 06:06:10 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k" 2025/04/04 06:06:10 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "qtq2f6qq4lgpsmj88vb7147qje3prudmtfdtr2342fth58vo9a50" --- PASS: TestSyncSuffixKeepExtension (22.44s) === RUN TestSyncUTFNorm run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-suxokod1xame'", Local "Local file system at /tmp/rclone1679136044", Modify Window "1ms" 2025/04/04 06:06:12 DEBUG : Testêé: md5 = f7028d47b50a15d4cfa7cb2d74ab400c OK 2025/04/04 06:06:13 DEBUG : Testêé: Sizes differ (src 14 vs dst 18) 2025/04/04 06:06:13 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-suxokod1xame': Waiting for checks to finish 2025/04/04 06:06:13 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-suxokod1xame': Waiting for transfers to finish 2025/04/04 06:06:14 DEBUG : Testêé: md5 = 61ae4ad5280cce248daef360a66acbbc OK 2025/04/04 06:06:14 INFO : Testêé: Copied (replaced existing) to: Testêé 2025/04/04 06:06:14 DEBUG : Waiting for deletions to finish --- PASS: TestSyncUTFNorm (3.94s) === RUN TestSyncImmutable run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-suxokod1xame'", Local "Local file system at /tmp/rclone1679136044", Modify Window "1ms" 2025/04/04 06:06:15 DEBUG : existing: Need to transfer - File not found at Destination 2025/04/04 06:06:15 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-suxokod1xame': Waiting for checks to finish 2025/04/04 06:06:15 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-suxokod1xame': Waiting for transfers to finish 2025/04/04 06:06:17 DEBUG : existing: md5 = ab68e0f9934c0ba84ecb2953762f9f01 OK 2025/04/04 06:06:17 INFO : existing: Copied (new) 2025/04/04 06:06:17 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-suxokod1xame'", Local "Local file system at /tmp/rclone1679136044", Modify Window "1ms" 2025/04/04 06:06:17 DEBUG : existing: Sizes differ (src 8 vs dst 6) 2025/04/04 06:06:17 ERROR : existing: Source and destination exist but do not match: immutable file modified 2025/04/04 06:06:17 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-suxokod1xame': Waiting for checks to finish 2025/04/04 06:06:17 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-suxokod1xame': Waiting for transfers to finish 2025/04/04 06:06:17 ERROR : Encrypted drive 'TestCryptDrive:rclone-test-suxokod1xame': not deleting files as there were IO errors 2025/04/04 06:06:17 ERROR : Encrypted drive 'TestCryptDrive:rclone-test-suxokod1xame': not deleting directories as there were IO errors run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-suxokod1xame'", Local "Local file system at /tmp/rclone1679136044", Modify Window "1ms" --- PASS: TestSyncImmutable (4.67s) === RUN TestSyncIgnoreCase run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-suxokod1xame'", Local "Local file system at /tmp/rclone1679136044", Modify Window "1ms" 2025/04/04 06:06:21 DEBUG : EXISTING: md5 = c2634b74b6c5ff623c22b484d8a73506 OK 2025/04/04 06:06:21 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-suxokod1xame': Waiting for checks to finish 2025/04/04 06:06:21 DEBUG : existing: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/04 06:06:21 DEBUG : existing: Unchanged skipping 2025/04/04 06:06:21 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-suxokod1xame': Waiting for transfers to finish 2025/04/04 06:06:21 DEBUG : Waiting for deletions to finish 2025/04/04 06:06:21 INFO : There was nothing to transfer --- PASS: TestSyncIgnoreCase (2.97s) === RUN TestFixCase run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-suxokod1xame'", Local "Local file system at /tmp/rclone1679136044", Modify Window "1ms" sync_test.go:2635: Skipping test as local or remote are case-sensitive --- SKIP: TestFixCase (0.44s) === RUN TestMaxTransfer === RUN TestMaxTransfer/Hard run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-suxokod1xame'", Local "Local file system at /tmp/rclone1679136044", 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-suxokod1xame'", Local "Local file system at /tmp/rclone1679136044", 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-suxokod1xame'", Local "Local file system at /tmp/rclone1679136044", Modify Window "1ms" sync_test.go:2674: This test only runs on local --- PASS: TestMaxTransfer (1.34s) --- SKIP: TestMaxTransfer/Hard (0.51s) --- SKIP: TestMaxTransfer/Soft (0.40s) --- SKIP: TestMaxTransfer/Cautious (0.43s) === RUN TestSyncConcurrentDelete run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-suxokod1xame'", Local "Local file system at /tmp/rclone1679136044", Modify Window "1ms" 2025/04/04 06:06:26 DEBUG : both0: md5 = 2c0bd385eafc12afb052fbe11f0167a3 OK 2025/04/04 06:06:27 DEBUG : only0: md5 = 56ee6f6231f3d1e339a66cda10752946 OK 2025/04/04 06:06:29 DEBUG : both1: md5 = db22c58191ae5b37b315ce096bea4058 OK 2025/04/04 06:06:30 DEBUG : only1: md5 = 2f8c3064f5e8b1c0082d504d9da000d1 OK 2025/04/04 06:06:32 DEBUG : both2: md5 = 0a9bcd4fc1ff427564564b79f7dfc0fc OK 2025/04/04 06:06:33 DEBUG : only2: md5 = ba5bc2b4c8f57a7a731813076cd99f61 OK 2025/04/04 06:06:34 DEBUG : both3: md5 = 393d1cd8efad9876c89f0406cf8f3c9f OK 2025/04/04 06:06:36 DEBUG : only3: md5 = efaeb487f1e5cf76907533531dbff035 OK 2025/04/04 06:06:37 DEBUG : both4: md5 = 6e93c4c283b9a45b8fcae8034b5fb634 OK 2025/04/04 06:06:38 DEBUG : only4: md5 = 71a3eb70dd1feed6707722dac5342485 OK 2025/04/04 06:06:40 DEBUG : both5: md5 = 40a344134af2a7c28975a2b0dad0daa2 OK 2025/04/04 06:06:41 DEBUG : only5: md5 = 4e36af409a4a4b1282c860f3a681c2fb OK 2025/04/04 06:06:42 DEBUG : both6: md5 = 50937155cf0354851994514d7f2f5195 OK 2025/04/04 06:06:44 DEBUG : only6: md5 = f1542b973b9100713ebad8ef48e63883 OK 2025/04/04 06:06:45 DEBUG : both7: md5 = deb3199f06aa43ab90ed900ddc2f9847 OK 2025/04/04 06:06:47 DEBUG : only7: md5 = 2e28ca843fbbb094c23db625eaff7b9a OK 2025/04/04 06:06:48 DEBUG : both8: md5 = 1d053d17e72265a44147ff06e77c44dd OK 2025/04/04 06:06:49 DEBUG : only8: md5 = 9dc1668cb8157b430370c726104865e1 OK 2025/04/04 06:06:51 DEBUG : both9: md5 = c741a2190c17fe5f9b434218d18a583d OK 2025/04/04 06:06:52 DEBUG : only9: md5 = 16185b59b2c2e9f1a410c87ae1a3332a OK 2025/04/04 06:06:53 DEBUG : both10: md5 = b615c6e6c4a68ef38e1d745e81670a29 OK 2025/04/04 06:06:55 DEBUG : only10: md5 = 2264aaef0ee175bcb9be0dc417ef7c17 OK 2025/04/04 06:06:56 DEBUG : both11: md5 = c0667bed4b097a49c0edf90fe4d2c8d4 OK 2025/04/04 06:06:57 DEBUG : only11: md5 = c267d02da6a626fe48f8b52fc038c146 OK 2025/04/04 06:06:59 DEBUG : both12: md5 = 2ad32f48a0fa8945ac575778e568eab6 OK 2025/04/04 06:07:00 DEBUG : only12: md5 = 73ea25385d5f27fd06efb284807f2f43 OK 2025/04/04 06:07:02 DEBUG : both13: md5 = b49e8797195045341826ab6081042cd5 OK 2025/04/04 06:07:03 DEBUG : only13: md5 = a2bd3ea00547e00094a3e578bdedb4c7 OK 2025/04/04 06:07:04 DEBUG : both14: md5 = 0973e612cbdee7acf15f6e8d98c7ae62 OK 2025/04/04 06:07:05 DEBUG : only14: md5 = e27c69182a923f185eb91d1b0d990a0c OK 2025/04/04 06:07:07 DEBUG : both15: md5 = bfe90ee75117cbaebb13b9ea8c226d1f OK 2025/04/04 06:07:08 DEBUG : only15: md5 = 7378cd95ddd465a6ab696023f21068ca OK 2025/04/04 06:07:09 DEBUG : both16: md5 = eea466ad78690ba2b8827405cec87104 OK 2025/04/04 06:07:10 DEBUG : only16: md5 = 28329931e783dba96b9be40ad9a460ba OK 2025/04/04 06:07:11 DEBUG : both17: md5 = 2be6ab88ad30712224d4d311fe440504 OK 2025/04/04 06:07:13 DEBUG : only17: md5 = 93e38dec377eaf9c6bf0cf4e12a833d1 OK 2025/04/04 06:07:14 DEBUG : both18: md5 = 73f059535d0e74e997bb557be6a9a302 OK 2025/04/04 06:07:16 DEBUG : only18: md5 = 115eebed5ff2bd3f2d89e938ed85f015 OK 2025/04/04 06:07:17 DEBUG : both19: md5 = 0364077ff3352262b720ed2f81ceb0cf OK 2025/04/04 06:07:18 DEBUG : only19: md5 = 5e8c748f4216b0a0409ebddbcf85dccd OK 2025/04/04 06:07:19 DEBUG : both0: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/04 06:07:19 DEBUG : both1: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/04 06:07:19 DEBUG : both10: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/04 06:07:19 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-suxokod1xame': Waiting for checks to finish 2025/04/04 06:07:19 DEBUG : both11: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/04 06:07:19 DEBUG : both0: Unchanged skipping 2025/04/04 06:07:19 DEBUG : both12: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/04 06:07:19 DEBUG : both1: Unchanged skipping 2025/04/04 06:07:19 DEBUG : both13: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/04 06:07:19 DEBUG : both13: Unchanged skipping 2025/04/04 06:07:19 DEBUG : both14: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/04 06:07:19 DEBUG : both14: Unchanged skipping 2025/04/04 06:07:19 DEBUG : both15: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/04 06:07:19 DEBUG : both15: Unchanged skipping 2025/04/04 06:07:19 DEBUG : both16: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/04 06:07:19 DEBUG : both16: Unchanged skipping 2025/04/04 06:07:19 DEBUG : both17: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/04 06:07:19 DEBUG : both17: Unchanged skipping 2025/04/04 06:07:19 DEBUG : both18: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/04 06:07:19 DEBUG : both18: Unchanged skipping 2025/04/04 06:07:19 DEBUG : both19: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/04 06:07:19 DEBUG : both19: Unchanged skipping 2025/04/04 06:07:19 DEBUG : both2: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/04 06:07:19 DEBUG : both2: Unchanged skipping 2025/04/04 06:07:19 DEBUG : both3: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/04 06:07:19 DEBUG : both3: Unchanged skipping 2025/04/04 06:07:19 DEBUG : both4: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/04 06:07:19 DEBUG : both4: Unchanged skipping 2025/04/04 06:07:19 DEBUG : both5: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/04 06:07:19 DEBUG : both5: Unchanged skipping 2025/04/04 06:07:19 DEBUG : both6: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/04 06:07:19 DEBUG : both6: Unchanged skipping 2025/04/04 06:07:19 DEBUG : both7: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/04 06:07:19 DEBUG : both7: Unchanged skipping 2025/04/04 06:07:19 DEBUG : both8: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/04 06:07:19 DEBUG : both8: Unchanged skipping 2025/04/04 06:07:19 DEBUG : both9: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/04 06:07:19 DEBUG : both9: Unchanged skipping 2025/04/04 06:07:19 DEBUG : both10: Unchanged skipping 2025/04/04 06:07:19 DEBUG : both11: Unchanged skipping 2025/04/04 06:07:19 DEBUG : both12: Unchanged skipping 2025/04/04 06:07:19 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-suxokod1xame': Waiting for transfers to finish 2025/04/04 06:07:19 DEBUG : Waiting for deletions to finish 2025/04/04 06:07:19 INFO : only1: Deleted 2025/04/04 06:07:19 INFO : only8: Deleted 2025/04/04 06:07:19 INFO : only5: Deleted 2025/04/04 06:07:19 INFO : only11: Deleted 2025/04/04 06:07:20 INFO : only14: Deleted 2025/04/04 06:07:20 INFO : only16: Deleted 2025/04/04 06:07:20 INFO : only10: Deleted 2025/04/04 06:07:20 INFO : only13: Deleted 2025/04/04 06:07:20 INFO : only2: Deleted 2025/04/04 06:07:20 INFO : only19: Deleted 2025/04/04 06:07:20 INFO : only9: Deleted 2025/04/04 06:07:20 INFO : only4: Deleted 2025/04/04 06:07:21 INFO : only0: Deleted 2025/04/04 06:07:21 INFO : only7: Deleted 2025/04/04 06:07:21 INFO : only3: Deleted 2025/04/04 06:07:21 INFO : only12: Deleted 2025/04/04 06:07:21 INFO : only15: Deleted 2025/04/04 06:07:21 INFO : only18: Deleted 2025/04/04 06:07:21 INFO : only6: Deleted 2025/04/04 06:07:21 INFO : only17: Deleted 2025/04/04 06:07:21 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-suxokod1xame'", Local "Local file system at /tmp/rclone1679136044", Modify Window "1ms" --- PASS: TestSyncConcurrentDelete (67.33s) === RUN TestSyncConcurrentTruncate run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-suxokod1xame'", Local "Local file system at /tmp/rclone1679136044", Modify Window "1ms" 2025/04/04 06:07:33 DEBUG : both0: md5 = fa816d4e3224ab7d6c1d62d9ffd0577e OK 2025/04/04 06:07:35 DEBUG : only0: md5 = d40f15fb25046df2cdf018bf5a43a606 OK 2025/04/04 06:07:36 DEBUG : both1: md5 = 286e2a065a4c6a0572f1af1c84542136 OK 2025/04/04 06:07:37 DEBUG : only1: md5 = 3100265dc223084e25aef4315c568734 OK 2025/04/04 06:07:39 DEBUG : both2: md5 = baf06453036f60359bbaec73c909d4df OK 2025/04/04 06:07:40 DEBUG : only2: md5 = de9a9f7ec9588ba798d84a2c6e7db04a OK 2025/04/04 06:07:41 DEBUG : both3: md5 = 93ac688b02778ec9e5be8811b2c6f8ca OK 2025/04/04 06:07:43 DEBUG : only3: md5 = 1fc75c2d8dfa309bd83f380197809f29 OK 2025/04/04 06:07:44 DEBUG : both4: md5 = 9251d40b24e774173ecb2e7e895db8da OK 2025/04/04 06:07:45 DEBUG : only4: md5 = 25053b3fc9ecb1047ecc83ff8bc70c0d OK 2025/04/04 06:07:47 DEBUG : both5: md5 = dd318c7e127b6c3e66754234e12cf92a OK 2025/04/04 06:07:48 DEBUG : only5: md5 = affcb8a30ab51e577d42b67ce92cc70a OK 2025/04/04 06:07:49 DEBUG : both6: md5 = e698624f517a2c02c65f0cc428f912a5 OK 2025/04/04 06:07:50 DEBUG : only6: md5 = 852232bf192ae203a92fac04fa5c170a OK 2025/04/04 06:07:52 DEBUG : both7: md5 = b3c8f482981d67b8be12d8006f5441c5 OK 2025/04/04 06:07:53 DEBUG : only7: md5 = 4f38d6f7671d0fc135b21037eb605812 OK 2025/04/04 06:07:54 DEBUG : both8: md5 = 9e55e9b0a0b7e59ed4df9cb76ce67056 OK 2025/04/04 06:07:56 DEBUG : only8: md5 = 308c3a04c2671502a3ea68c60873fa08 OK 2025/04/04 06:07:57 DEBUG : both9: md5 = 7c33563bbfb6ff3ddb35183dbb9e0c00 OK 2025/04/04 06:07:58 DEBUG : only9: md5 = 86e83a1514196f5d76edee418295f9da OK 2025/04/04 06:08:00 DEBUG : both10: md5 = c671f50babbe72bafc99f6153ed4626a OK 2025/04/04 06:08:01 DEBUG : only10: md5 = 7b3a0226cf2025586fdfec3a1576f619 OK 2025/04/04 06:08:03 DEBUG : both11: md5 = 48f77e8fe95f8ceab8e33edfdb49af54 OK 2025/04/04 06:08:04 DEBUG : only11: md5 = f4730aa2f33a0cc2ef73a45a41d3b9eb OK 2025/04/04 06:08:05 DEBUG : both12: md5 = acca2b34807ec5c2ede00e4cbc8f2fbe OK 2025/04/04 06:08:07 DEBUG : only12: md5 = d1c6b6019e2b87bfcfddc2c75afebd16 OK 2025/04/04 06:08:08 DEBUG : both13: md5 = eda122d06a867dd70949f79e603f5421 OK 2025/04/04 06:08:09 DEBUG : only13: md5 = f6d39068ca3d5163ec9ffbd90ba1caca OK 2025/04/04 06:08:11 DEBUG : both14: md5 = 05273cd641897098a42670f83226e78a OK 2025/04/04 06:08:12 DEBUG : only14: md5 = f274ca77baad5cab2c23757b8ca0388e OK 2025/04/04 06:08:13 DEBUG : both15: md5 = a299638f090d136420437a61a6444df0 OK 2025/04/04 06:08:14 DEBUG : only15: md5 = 84df030de1c6338dc89f5bdc5453392b OK 2025/04/04 06:08:16 DEBUG : both16: md5 = 4c4303eb0e331eb8172a9c049235012f OK 2025/04/04 06:08:17 DEBUG : only16: md5 = fdb026dd15ac0ab40f9971ee838bee1a OK 2025/04/04 06:08:18 DEBUG : both17: md5 = 0012acf11f6cd9140aec6fd823cfbbbf OK 2025/04/04 06:08:20 DEBUG : only17: md5 = bc2a0668aa3be84966f907fd6f166679 OK 2025/04/04 06:08:21 DEBUG : both18: md5 = 993f432e5ce6d090431940dc54af907b OK 2025/04/04 06:08:22 DEBUG : only18: md5 = dd31cc587469d9f28e9c5ba2d2958389 OK 2025/04/04 06:08:23 DEBUG : both19: md5 = 289c19ae9e564a9462fafa0a90d755fd OK 2025/04/04 06:08:25 DEBUG : only19: md5 = 4a31c0944d1248265d9fcb03b2f2b6cb OK 2025/04/04 06:08:26 DEBUG : both0: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/04 06:08:26 DEBUG : both0: Unchanged skipping 2025/04/04 06:08:26 DEBUG : both1: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/04 06:08:26 DEBUG : both1: Unchanged skipping 2025/04/04 06:08:26 DEBUG : both10: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/04 06:08:26 DEBUG : both11: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/04 06:08:26 DEBUG : both12: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/04 06:08:26 DEBUG : both13: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/04 06:08:26 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-suxokod1xame': Waiting for checks to finish 2025/04/04 06:08:26 DEBUG : both10: Unchanged skipping 2025/04/04 06:08:26 DEBUG : both14: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/04 06:08:26 DEBUG : both11: Unchanged skipping 2025/04/04 06:08:26 DEBUG : both15: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/04 06:08:26 DEBUG : both12: Unchanged skipping 2025/04/04 06:08:26 DEBUG : both16: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/04 06:08:26 DEBUG : both13: Unchanged skipping 2025/04/04 06:08:26 DEBUG : both17: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/04 06:08:26 DEBUG : both14: Unchanged skipping 2025/04/04 06:08:26 DEBUG : both18: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/04 06:08:26 DEBUG : both18: Unchanged skipping 2025/04/04 06:08:26 DEBUG : both19: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/04 06:08:26 DEBUG : both15: Unchanged skipping 2025/04/04 06:08:26 DEBUG : both16: Unchanged skipping 2025/04/04 06:08:26 DEBUG : both3: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/04 06:08:26 DEBUG : both17: Unchanged skipping 2025/04/04 06:08:26 DEBUG : both19: Unchanged skipping 2025/04/04 06:08:26 DEBUG : both4: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/04 06:08:26 DEBUG : both2: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/04 06:08:26 DEBUG : both5: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/04 06:08:26 DEBUG : both3: Unchanged skipping 2025/04/04 06:08:26 DEBUG : both6: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/04 06:08:26 DEBUG : both4: Unchanged skipping 2025/04/04 06:08:26 DEBUG : both2: Unchanged skipping 2025/04/04 06:08:26 DEBUG : both8: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/04 06:08:26 DEBUG : both5: Unchanged skipping 2025/04/04 06:08:26 DEBUG : both9: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/04 06:08:26 DEBUG : both6: Unchanged skipping 2025/04/04 06:08:26 DEBUG : only0: Sizes differ (src 0 vs dst 6) 2025/04/04 06:08:26 DEBUG : both7: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/04 06:08:26 DEBUG : both8: Unchanged skipping 2025/04/04 06:08:26 DEBUG : only1: Sizes differ (src 0 vs dst 6) 2025/04/04 06:08:26 DEBUG : both9: Unchanged skipping 2025/04/04 06:08:26 DEBUG : only11: Sizes differ (src 0 vs dst 6) 2025/04/04 06:08:26 DEBUG : both7: Unchanged skipping 2025/04/04 06:08:26 DEBUG : only12: Sizes differ (src 0 vs dst 6) 2025/04/04 06:08:26 DEBUG : only10: Sizes differ (src 0 vs dst 6) 2025/04/04 06:08:26 DEBUG : only13: Sizes differ (src 0 vs dst 6) 2025/04/04 06:08:26 DEBUG : only14: Sizes differ (src 0 vs dst 6) 2025/04/04 06:08:26 DEBUG : only15: Sizes differ (src 0 vs dst 6) 2025/04/04 06:08:26 DEBUG : only16: Sizes differ (src 0 vs dst 6) 2025/04/04 06:08:26 DEBUG : only2: Sizes differ (src 0 vs dst 6) 2025/04/04 06:08:26 DEBUG : only17: Sizes differ (src 0 vs dst 6) 2025/04/04 06:08:26 DEBUG : only18: Sizes differ (src 0 vs dst 6) 2025/04/04 06:08:26 DEBUG : only19: Sizes differ (src 0 vs dst 6) 2025/04/04 06:08:26 DEBUG : only3: Sizes differ (src 0 vs dst 6) 2025/04/04 06:08:26 DEBUG : only4: Sizes differ (src 0 vs dst 6) 2025/04/04 06:08:26 DEBUG : only5: Sizes differ (src 0 vs dst 6) 2025/04/04 06:08:26 DEBUG : only6: Sizes differ (src 0 vs dst 6) 2025/04/04 06:08:26 DEBUG : only7: Sizes differ (src 0 vs dst 6) 2025/04/04 06:08:26 DEBUG : only8: Sizes differ (src 0 vs dst 6) 2025/04/04 06:08:26 DEBUG : only9: Sizes differ (src 0 vs dst 6) 2025/04/04 06:08:26 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-suxokod1xame': Waiting for transfers to finish 2025/04/04 06:08:27 DEBUG : only11: md5 = 1c3c3d15aa52750b96aa97ec088d172b OK 2025/04/04 06:08:27 INFO : only11: Copied (replaced existing) 2025/04/04 06:08:27 DEBUG : only12: md5 = b466cb2f4e031afdd5dfc140886cf615 OK 2025/04/04 06:08:27 INFO : only12: Copied (replaced existing) 2025/04/04 06:08:27 DEBUG : only1: md5 = bfedb2a993ebd71e35d15dda2f3f47fa OK 2025/04/04 06:08:27 INFO : only1: Copied (replaced existing) 2025/04/04 06:08:27 DEBUG : only0: md5 = 5976221c7fe8f0310b1b22eaf208cebf OK 2025/04/04 06:08:27 INFO : only0: Copied (replaced existing) 2025/04/04 06:08:28 DEBUG : only10: md5 = 7ac1eead3475c3434e10bbb7a5e03782 OK 2025/04/04 06:08:28 INFO : only10: Copied (replaced existing) 2025/04/04 06:08:28 DEBUG : only14: md5 = 42b91c6a11987550893bdc018de65a34 OK 2025/04/04 06:08:28 INFO : only14: Copied (replaced existing) 2025/04/04 06:08:28 DEBUG : only13: md5 = c9b976ff2defd38f05b5a73af27dbbc7 OK 2025/04/04 06:08:28 INFO : only13: Copied (replaced existing) 2025/04/04 06:08:28 DEBUG : only15: md5 = 4df989265bc7c50865ce074fe80e20c2 OK 2025/04/04 06:08:28 INFO : only15: Copied (replaced existing) 2025/04/04 06:08:29 DEBUG : only16: md5 = 50eb0d13e8f8e647ab6c8246d1d68c61 OK 2025/04/04 06:08:29 INFO : only16: Copied (replaced existing) 2025/04/04 06:08:29 DEBUG : only2: md5 = 0fae430c229abc42e3292241ec48308b OK 2025/04/04 06:08:29 INFO : only2: Copied (replaced existing) 2025/04/04 06:08:29 DEBUG : only3: md5 = 618eb85dcb727b39f05a58641770ab4e OK 2025/04/04 06:08:29 INFO : only3: Copied (replaced existing) 2025/04/04 06:08:29 DEBUG : only17: md5 = 90576e22f25577db4e360f2cba75c7aa OK 2025/04/04 06:08:29 INFO : only17: Copied (replaced existing) 2025/04/04 06:08:30 DEBUG : only18: md5 = f6b682502fc09f29069b3bc9e0ad5ecf OK 2025/04/04 06:08:30 INFO : only18: Copied (replaced existing) 2025/04/04 06:08:30 DEBUG : only4: md5 = 780aae86690d426e87c5813a7627bfb4 OK 2025/04/04 06:08:30 INFO : only4: Copied (replaced existing) 2025/04/04 06:08:30 DEBUG : only19: md5 = 13cac4669d68aa0d9b02ca6b9ef37fed OK 2025/04/04 06:08:30 INFO : only19: Copied (replaced existing) 2025/04/04 06:08:30 DEBUG : only5: md5 = e05ec13a837b35b896aa719ef58d20c9 OK 2025/04/04 06:08:30 INFO : only5: Copied (replaced existing) 2025/04/04 06:08:31 DEBUG : only9: md5 = 4bddf6ac5ba3b5a6fb95a1a5ae6ab747 OK 2025/04/04 06:08:31 INFO : only9: Copied (replaced existing) 2025/04/04 06:08:31 DEBUG : only6: md5 = d549ef68d0853881766dcc15def32fa9 OK 2025/04/04 06:08:31 INFO : only6: Copied (replaced existing) 2025/04/04 06:08:31 DEBUG : only8: md5 = 53c9be4789bccae391a8d6f1e6fb4d39 OK 2025/04/04 06:08:31 INFO : only8: Copied (replaced existing) 2025/04/04 06:08:31 DEBUG : only7: md5 = 6e4007271f9cce89d35b91e3fbecc4f8 OK 2025/04/04 06:08:31 INFO : only7: Copied (replaced existing) 2025/04/04 06:08:31 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-suxokod1xame'", Local "Local file system at /tmp/rclone1679136044", Modify Window "1ms" --- PASS: TestSyncConcurrentTruncate (78.51s) === RUN TestSyncReplaceDirModTime run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-suxokod1xame'", Local "Local file system at /tmp/rclone1679136044", Modify Window "1ms" 2025/04/04 06:08:50 DEBUG : empty_dir: Making directory with metadata 2025/04/04 06:08:50 INFO : empty_dir: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2025/04/04 06:08:50 DEBUG : empty_on_remote: Making directory with metadata 2025/04/04 06:08:50 INFO : empty_on_remote: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2025/04/04 06:08:50 DEBUG : empty_on_remote: Making directory with metadata 2025/04/04 06:08:51 INFO : empty_on_remote: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-suxokod1xame'", Local "Local file system at /tmp/rclone1679136044", Modify Window "1ms" 2025/04/04 06:08:56 INFO : test_dir1: Set directory modification time (using DirSetModTime) 2025/04/04 06:08:56 INFO : test_dir2: Set directory modification time (using DirSetModTime) 2025/04/04 06:08:56 INFO : test_dir2/sub_dir: Set directory modification time (using DirSetModTime) 2025/04/04 06:08:56 INFO : empty_on_remote: Set directory modification time (using DirSetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-suxokod1xame'", Local "Local file system at /tmp/rclone1679136044", Modify Window "1ms" 2025/04/04 06:09:03 DEBUG : heqj02jg0dcqlem7gl0500bvp0/24g2k8bseitblkmqnie1ibl2s8: Rmdir: contains trashed file: "633fmaa0qic3kv3cladnu11pto" 2025/04/04 06:09:03 DEBUG : heqj02jg0dcqlem7gl0500bvp0: Rmdir: contains trashed file: "24g2k8bseitblkmqnie1ibl2s8" 2025/04/04 06:09:04 DEBUG : gq68srrpl0nnf394bgf7dbu9kc: Rmdir: contains trashed file: "d26uovf0miqhd1mu3c9jbseq00" --- PASS: TestSyncReplaceDirModTime (15.98s) === RUN TestSyncReplaceDirModTimeWithEmptyDirs run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-suxokod1xame'", Local "Local file system at /tmp/rclone1679136044", Modify Window "1ms" 2025/04/04 06:09:06 DEBUG : empty_dir: Making directory with metadata 2025/04/04 06:09:06 INFO : empty_dir: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2025/04/04 06:09:06 DEBUG : empty_on_remote: Making directory with metadata 2025/04/04 06:09:06 INFO : empty_on_remote: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2025/04/04 06:09:06 DEBUG : empty_on_remote: Making directory with metadata 2025/04/04 06:09:07 INFO : empty_on_remote: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-suxokod1xame'", Local "Local file system at /tmp/rclone1679136044", Modify Window "1ms" 2025/04/04 06:09:11 INFO : test_dir1: Set directory modification time (using DirSetModTime) 2025/04/04 06:09:11 INFO : test_dir2: Set directory modification time (using DirSetModTime) 2025/04/04 06:09:11 INFO : test_dir2/sub_dir: Set directory modification time (using DirSetModTime) 2025/04/04 06:09:11 INFO : empty_on_remote: Set directory modification time (using DirSetModTime) 2025/04/04 06:09:11 INFO : empty_dir: Set directory modification time (using DirSetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-suxokod1xame'", Local "Local file system at /tmp/rclone1679136044", Modify Window "1ms" 2025/04/04 06:09:19 DEBUG : heqj02jg0dcqlem7gl0500bvp0/24g2k8bseitblkmqnie1ibl2s8: Rmdir: contains trashed file: "633fmaa0qic3kv3cladnu11pto" 2025/04/04 06:09:20 DEBUG : heqj02jg0dcqlem7gl0500bvp0: Rmdir: contains trashed file: "24g2k8bseitblkmqnie1ibl2s8" 2025/04/04 06:09:20 DEBUG : gq68srrpl0nnf394bgf7dbu9kc: Rmdir: contains trashed file: "d26uovf0miqhd1mu3c9jbseq00" --- PASS: TestSyncReplaceDirModTimeWithEmptyDirs (17.35s) === RUN TestNothingToTransferWithEmptyDirs run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-suxokod1xame'", Local "Local file system at /tmp/rclone1679136044", Modify Window "1ms" 2025/04/04 06:09:23 INFO : sub dir: Set directory modification time (using DirSetModTime) 2025/04/04 06:09:23 DEBUG : sub dir: Making directory with metadata 2025/04/04 06:09:24 INFO : sub dir: Made directory with metadata (mtime=2011-12-30T12:59:59Z) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-suxokod1xame'", Local "Local file system at /tmp/rclone1679136044", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-suxokod1xame'", Local "Local file system at /tmp/rclone1679136044", Modify Window "1ms" 2025/04/04 06:09:42 INFO : sub dir2: Set directory modification time (using DirSetModTime) 2025/04/04 06:09:42 INFO : sub dir2: Set directory modification time (using DirSetModTime) 2025/04/04 06:09:42 INFO : sub dirEmpty/sub dirEmpty2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2025/04/04 06:09:42 INFO : sub dirEmpty: Set directory modification time (using DirSetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-suxokod1xame'", Local "Local file system at /tmp/rclone1679136044", Modify Window "1ms" 2025/04/04 06:09:56 DEBUG : gcsdkq814sbtppue42dpsbg8ug: Rmdir: contains trashed file: "sjuo65gk5q3r1199jselk9k9o0" 2025/04/04 06:09:56 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/37qp6d1gohacv723ij3brofbu8/i24n0ln37pa2hv8pctddeuh73o: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" 2025/04/04 06:09:57 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/37qp6d1gohacv723ij3brofbu8: Rmdir: contains trashed file: "i24n0ln37pa2hv8pctddeuh73o" 2025/04/04 06:09:58 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "37qp6d1gohacv723ij3brofbu8" 2025/04/04 06:09:58 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak" 2025/04/04 06:09:59 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak" 2025/04/04 06:10:00 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak" 2025/04/04 06:10:00 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak" 2025/04/04 06:10:01 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/4r13oncfa2rsrr82oqhsqv24ns: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" 2025/04/04 06:10:02 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc: Rmdir: contains trashed file: "4r13oncfa2rsrr82oqhsqv24ns" 2025/04/04 06:10:02 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak" 2025/04/04 06:10:03 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestNothingToTransferWithEmptyDirs (41.03s) === RUN TestNothingToTransferWithoutEmptyDirs run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-suxokod1xame'", Local "Local file system at /tmp/rclone1679136044", Modify Window "1ms" 2025/04/04 06:10:05 INFO : sub dir: Set directory modification time (using DirSetModTime) 2025/04/04 06:10:05 DEBUG : sub dir: Making directory with metadata 2025/04/04 06:10:05 INFO : sub dir: Made directory with metadata (mtime=2011-12-30T12:59:59Z) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-suxokod1xame'", Local "Local file system at /tmp/rclone1679136044", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-suxokod1xame'", Local "Local file system at /tmp/rclone1679136044", Modify Window "1ms" 2025/04/04 06:10:26 INFO : sub dir2: Set directory modification time (using DirSetModTime) 2025/04/04 06:10:27 INFO : sub dir2: Set directory modification time (using DirSetModTime) 2025/04/04 06:10:27 INFO : sub dirEmpty/sub dirEmpty2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2025/04/04 06:10:27 INFO : sub dirEmpty: Set directory modification time (using DirSetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-suxokod1xame'", Local "Local file system at /tmp/rclone1679136044", Modify Window "1ms" 2025/04/04 06:10:40 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/37qp6d1gohacv723ij3brofbu8/i24n0ln37pa2hv8pctddeuh73o: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" 2025/04/04 06:10:40 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/37qp6d1gohacv723ij3brofbu8: Rmdir: contains trashed file: "i24n0ln37pa2hv8pctddeuh73o" 2025/04/04 06:10:41 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "37qp6d1gohacv723ij3brofbu8" 2025/04/04 06:10:42 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak" 2025/04/04 06:10:42 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak" 2025/04/04 06:10:43 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak" 2025/04/04 06:10:44 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak" 2025/04/04 06:10:45 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/4r13oncfa2rsrr82oqhsqv24ns: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" 2025/04/04 06:10:45 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc: Rmdir: contains trashed file: "4r13oncfa2rsrr82oqhsqv24ns" 2025/04/04 06:10:45 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak" 2025/04/04 06:10:46 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestNothingToTransferWithoutEmptyDirs (43.56s) PASS 2025/04/04 06:10:48 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-suxokod1xame': Purge remote "./sync.test -test.v -test.timeout 1h0m0s -remote TestCryptDrive: -verbose -fast-list" - Finished OK in 15m31.313700845s (try 1/5)