"./sync.test -test.v -test.timeout 1h0m0s -remote TestCryptDrive: -verbose" - Starting (try 1/5) 2025/03/06 01:43:33 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-yowelix7taho" 2025/03/06 01:43:33 DEBUG : Using config file from "/home/rclone/.rclone.conf" 2025/03/06 01:43:33 DEBUG : Creating backend with remote "TestDrive:crypt/bi3hem14btfb1nqq3d26d65889gu06un3tb12s4cc9d4a0j3cgu0" 2025/03/06 01:43:34 DEBUG : Creating backend with remote "/tmp/rclone3247573043" === RUN TestPipe --- PASS: TestPipe (0.00s) === RUN TestPipeConcurrent --- PASS: TestPipeConcurrent (0.03s) === 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-yowelix7taho'", Local "Local file system at /tmp/rclone3247573043", Modify Window "1ms" 2025/03/06 01:43:35 DEBUG : Added delayed dir = "sub dir", newDst= 2025/03/06 01:43:35 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2025/03/06 01:43:35 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yowelix7taho': Waiting for checks to finish 2025/03/06 01:43:35 NOTICE: sub dir/hello world: Skipped copy as --dry-run is set (size 11) 2025/03/06 01:43:35 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yowelix7taho': Waiting for transfers to finish 2025/03/06 01:43:35 NOTICE: sub dir: Skipped set directory modification time as --dry-run is set run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-yowelix7taho'", Local "Local file system at /tmp/rclone3247573043", Modify Window "1ms" --- PASS: TestCopyWithDryRun (2.13s) === RUN TestCopy run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-yowelix7taho'", Local "Local file system at /tmp/rclone3247573043", Modify Window "1ms" 2025/03/06 01:43:36 INFO : sub dir: Set directory modification time (using DirSetModTime) 2025/03/06 01:43:36 DEBUG : Added delayed dir = "sub dir", newDst= 2025/03/06 01:43:36 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2025/03/06 01:43:36 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yowelix7taho': Waiting for checks to finish 2025/03/06 01:43:36 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yowelix7taho': Waiting for transfers to finish 2025/03/06 01:43:38 DEBUG : sub dir/hello world: md5 = 679557760aee80579de3769dddde2e75 OK 2025/03/06 01:43:38 INFO : sub dir/hello world: Copied (new) 2025/03/06 01:43:39 INFO : sub dir: Set directory modification time (using DirSetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-yowelix7taho'", Local "Local file system at /tmp/rclone3247573043", Modify Window "1ms" 2025/03/06 01:43:41 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestCopy (5.96s) === RUN TestCopyMetadata run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-yowelix7taho'", Local "Local file system at /tmp/rclone3247573043", Modify Window "1ms" 2025/03/06 01:43:42 DEBUG : metadata sub dir: Making directory with metadata 2025/03/06 01:43:42 INFO : metadata sub dir: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2025/03/06 01:43:42 DEBUG : empty metadata sub dir: Making directory with metadata 2025/03/06 01:43:42 INFO : empty metadata sub dir: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2025/03/06 01:43:42 DEBUG : Local file system at /tmp/rclone3247573043: File to upload is small (21 bytes), uploading instead of streaming 2025/03/06 01:43:42 DEBUG : metadata sub dir/hello metadata world: md5 = baa7a013449dbba2b1ed02b5cfb4e1a2 OK 2025/03/06 01:43:42 DEBUG : metadata sub dir/hello metadata world: Size and md5 of src and dst objects identical 2025/03/06 01:43:42 INFO : metadata sub dir: Set directory modification time (using DirSetModTime) 2025/03/06 01:43:42 DEBUG : Google drive root 'crypt/bi3hem14btfb1nqq3d26d65889gu06un3tb12s4cc9d4a0j3cgu0': Skipping btime metadata as can't update it on an existing file: 2025-03-06T01:43:42.295026347Z 2025/03/06 01:43:43 INFO : empty metadata sub dir: Updated directory metadata 2025/03/06 01:43:43 DEBUG : Google drive root 'crypt/bi3hem14btfb1nqq3d26d65889gu06un3tb12s4cc9d4a0j3cgu0': Skipping btime metadata as can't update it on an existing file: 2025-03-06T01:43:42.295026347Z 2025/03/06 01:43:44 INFO : metadata sub dir: Updated directory metadata 2025/03/06 01:43:44 DEBUG : metadata sub dir/hello metadata world: Need to transfer - File not found at Destination 2025/03/06 01:43:44 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yowelix7taho': Waiting for checks to finish 2025/03/06 01:43:44 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yowelix7taho': Waiting for transfers to finish 2025/03/06 01:43:45 DEBUG : metadata sub dir/hello metadata world: md5 = 00603f8a198451829692ec58e46a0eae OK 2025/03/06 01:43:45 INFO : metadata sub dir/hello metadata world: Copied (new) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-yowelix7taho'", Local "Local file system at /tmp/rclone3247573043", Modify Window "1ms" 2025/03/06 01:43:48 DEBUG : fg45q1rm3kh00nmmkk4m6ihmrcnel1p7551kqhjr9bk2gtd2gbf0: Rmdir: contains trashed file: "dmuvulfij81f693ur0f1vvbvq9v6iscp56daas3m51n9li5e3470" --- PASS: TestCopyMetadata (7.74s) === RUN TestCopyMetadataNoEmptyDirs run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-yowelix7taho'", Local "Local file system at /tmp/rclone3247573043", Modify Window "1ms" 2025/03/06 01:43:50 DEBUG : metadata sub dir: Making directory with metadata 2025/03/06 01:43:50 INFO : metadata sub dir: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2025/03/06 01:43:50 DEBUG : empty metadata sub dir: Making directory with metadata 2025/03/06 01:43:50 INFO : empty metadata sub dir: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2025/03/06 01:43:50 DEBUG : Local file system at /tmp/rclone3247573043: File to upload is small (21 bytes), uploading instead of streaming 2025/03/06 01:43:50 DEBUG : metadata sub dir/hello metadata world: md5 = baa7a013449dbba2b1ed02b5cfb4e1a2 OK 2025/03/06 01:43:50 DEBUG : metadata sub dir/hello metadata world: Size and md5 of src and dst objects identical 2025/03/06 01:43:50 INFO : metadata sub dir: Set directory modification time (using DirSetModTime) 2025/03/06 01:43:50 DEBUG : Added delayed dir = "empty metadata sub dir", newDst= 2025/03/06 01:43:50 DEBUG : Added delayed dir = "metadata sub dir", newDst= 2025/03/06 01:43:50 DEBUG : metadata sub dir/hello metadata world: Need to transfer - File not found at Destination 2025/03/06 01:43:50 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yowelix7taho': Waiting for checks to finish 2025/03/06 01:43:50 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yowelix7taho': Waiting for transfers to finish 2025/03/06 01:43:52 DEBUG : metadata sub dir/hello metadata world: md5 = 7ca1be2ff882db54a679f435087cb0a0 OK 2025/03/06 01:43:52 INFO : metadata sub dir/hello metadata world: Copied (new) 2025/03/06 01:43:52 DEBUG : Google drive root 'crypt/bi3hem14btfb1nqq3d26d65889gu06un3tb12s4cc9d4a0j3cgu0': Skipping btime metadata as can't update it on an existing file: 2025-03-06T01:43:50.038948573Z 2025/03/06 01:43:52 INFO : metadata sub dir: Updated directory metadata run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-yowelix7taho'", Local "Local file system at /tmp/rclone3247573043", Modify Window "1ms" 2025/03/06 01:43:55 DEBUG : fg45q1rm3kh00nmmkk4m6ihmrcnel1p7551kqhjr9bk2gtd2gbf0: Rmdir: contains trashed file: "dmuvulfij81f693ur0f1vvbvq9v6iscp56daas3m51n9li5e3470" --- PASS: TestCopyMetadataNoEmptyDirs (6.64s) === RUN TestCopyMissingDirectory run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-yowelix7taho'", Local "Local file system at /tmp/rclone3247573043", Modify Window "1ms" 2025/03/06 01:43:56 DEBUG : Creating backend with remote "/non-existing" 2025/03/06 01:43:56 ERROR : Local file system at /non-existing: error reading source root directory: directory not found 2025/03/06 01:43:56 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yowelix7taho': Waiting for checks to finish 2025/03/06 01:43:56 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yowelix7taho': Waiting for transfers to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-yowelix7taho'", Local "Local file system at /tmp/rclone3247573043", Modify Window "1ms" --- PASS: TestCopyMissingDirectory (1.17s) === RUN TestCopyNoTraverse run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-yowelix7taho'", Local "Local file system at /tmp/rclone3247573043", Modify Window "1ms" 2025/03/06 01:43:57 DEBUG : Added delayed dir = "sub dir", newDst= 2025/03/06 01:43:58 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2025/03/06 01:43:58 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yowelix7taho': Waiting for checks to finish 2025/03/06 01:43:58 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yowelix7taho': Waiting for transfers to finish 2025/03/06 01:44:00 DEBUG : sub dir/hello world: md5 = dd102e8adebb7ac3ae46681beae846a0 OK 2025/03/06 01:44:00 INFO : sub dir/hello world: Copied (new) 2025/03/06 01:44:00 INFO : sub dir: Set directory modification time (using DirSetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-yowelix7taho'", Local "Local file system at /tmp/rclone3247573043", Modify Window "1ms" 2025/03/06 01:44:02 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestCopyNoTraverse (5.61s) === RUN TestCopyCheckFirst run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-yowelix7taho'", Local "Local file system at /tmp/rclone3247573043", Modify Window "1ms" 2025/03/06 01:44:03 INFO : Encrypted drive 'TestCryptDrive:rclone-test-yowelix7taho': Running all checks before starting transfers 2025/03/06 01:44:03 DEBUG : Added delayed dir = "sub dir", newDst= 2025/03/06 01:44:03 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2025/03/06 01:44:03 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yowelix7taho': Waiting for checks to finish 2025/03/06 01:44:03 INFO : Encrypted drive 'TestCryptDrive:rclone-test-yowelix7taho': Checks finished, now starting transfers 2025/03/06 01:44:03 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yowelix7taho': Waiting for transfers to finish 2025/03/06 01:44:05 DEBUG : sub dir/hello world: md5 = 50959c1325cf6e39a7694caaf8291afa OK 2025/03/06 01:44:05 INFO : sub dir/hello world: Copied (new) 2025/03/06 01:44:06 INFO : sub dir: Set directory modification time (using DirSetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-yowelix7taho'", Local "Local file system at /tmp/rclone3247573043", Modify Window "1ms" 2025/03/06 01:44:08 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestCopyCheckFirst (5.73s) === RUN TestSyncNoTraverse run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-yowelix7taho'", Local "Local file system at /tmp/rclone3247573043", Modify Window "1ms" 2025/03/06 01:44:09 ERROR : Ignoring --no-traverse with sync 2025/03/06 01:44:09 DEBUG : Added delayed dir = "sub dir", newDst= 2025/03/06 01:44:09 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2025/03/06 01:44:09 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yowelix7taho': Waiting for checks to finish 2025/03/06 01:44:09 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yowelix7taho': Waiting for transfers to finish 2025/03/06 01:44:11 DEBUG : sub dir/hello world: md5 = b1b1e9c87ec4e83c81b9b482cde0201e OK 2025/03/06 01:44:11 INFO : sub dir/hello world: Copied (new) 2025/03/06 01:44:11 DEBUG : Waiting for deletions to finish 2025/03/06 01:44:11 INFO : sub dir: Set directory modification time (using DirSetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-yowelix7taho'", Local "Local file system at /tmp/rclone3247573043", Modify Window "1ms" 2025/03/06 01:44:13 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestSyncNoTraverse (5.60s) === RUN TestCopyWithDepth run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-yowelix7taho'", Local "Local file system at /tmp/rclone3247573043", Modify Window "1ms" 2025/03/06 01:44:15 DEBUG : hello world2: Need to transfer - File not found at Destination 2025/03/06 01:44:15 DEBUG : Added delayed dir = "sub dir", newDst= 2025/03/06 01:44:15 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yowelix7taho': Waiting for checks to finish 2025/03/06 01:44:15 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yowelix7taho': Waiting for transfers to finish 2025/03/06 01:44:16 DEBUG : hello world2: md5 = 944517026527781176038392f184cd97 OK 2025/03/06 01:44:16 INFO : hello world2: Copied (new) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-yowelix7taho'", Local "Local file system at /tmp/rclone3247573043", Modify Window "1ms" --- PASS: TestCopyWithDepth (3.21s) === RUN TestCopyWithFilesFrom run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-yowelix7taho'", Local "Local file system at /tmp/rclone3247573043", Modify Window "1ms" 2025/03/06 01:44:18 DEBUG : potato2: Need to transfer - File not found at Destination 2025/03/06 01:44:18 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yowelix7taho': Waiting for checks to finish 2025/03/06 01:44:18 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yowelix7taho': Waiting for transfers to finish 2025/03/06 01:44:19 DEBUG : potato2: md5 = b20eda9b49ba45afda81c5d35157d93c OK 2025/03/06 01:44:19 INFO : potato2: Copied (new) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-yowelix7taho'", Local "Local file system at /tmp/rclone3247573043", Modify Window "1ms" --- PASS: TestCopyWithFilesFrom (3.31s) === RUN TestCopyWithFilesFromAndNoTraverse run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-yowelix7taho'", Local "Local file system at /tmp/rclone3247573043", Modify Window "1ms" 2025/03/06 01:44:21 DEBUG : potato2: Need to transfer - File not found at Destination 2025/03/06 01:44:21 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yowelix7taho': Waiting for checks to finish 2025/03/06 01:44:21 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yowelix7taho': Waiting for transfers to finish 2025/03/06 01:44:22 DEBUG : potato2: md5 = 44336be0a18f6e8d260ecafb64fa01bf OK 2025/03/06 01:44:22 INFO : potato2: Copied (new) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-yowelix7taho'", Local "Local file system at /tmp/rclone3247573043", Modify Window "1ms" --- PASS: TestCopyWithFilesFromAndNoTraverse (3.33s) === RUN TestCopyEmptyDirectories run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-yowelix7taho'", Local "Local file system at /tmp/rclone3247573043", Modify Window "1ms" 2025/03/06 01:44:24 DEBUG : sub dir2/sub sub dir2: Making directory with metadata 2025/03/06 01:44:24 INFO : sub dir2/sub sub dir2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2025/03/06 01:44:24 INFO : sub dir2: Set directory modification time (using DirSetModTime) 2025/03/06 01:44:24 INFO : sub dir: Set directory modification time (using DirSetModTime) 2025/03/06 01:44:24 DEBUG : sub dir: Making directory with metadata 2025/03/06 01:44:25 INFO : sub dir: Made directory with metadata (mtime=2001-02-03T04:05:06.499999999Z) 2025/03/06 01:44:25 DEBUG : sub dir2: Making directory with metadata 2025/03/06 01:44:26 INFO : sub dir2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2025/03/06 01:44:26 DEBUG : sub dir2/sub sub dir2: Making directory with metadata 2025/03/06 01:44:26 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2025/03/06 01:44:27 INFO : sub dir2/sub sub dir2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2025/03/06 01:44:27 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yowelix7taho': Waiting for checks to finish 2025/03/06 01:44:27 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yowelix7taho': Waiting for transfers to finish 2025/03/06 01:44:28 DEBUG : sub dir/hello world: md5 = 385a3673a294ecb673280a9b558570d9 OK 2025/03/06 01:44:28 INFO : sub dir/hello world: Copied (new) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-yowelix7taho'", Local "Local file system at /tmp/rclone3247573043", Modify Window "1ms" 2025/03/06 01:44:31 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc: Rmdir: contains trashed file: "cv6a9uf28ngrajena8kt5ijjn0" 2025/03/06 01:44:32 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestCopyEmptyDirectories (8.87s) === RUN TestCopyNoEmptyDirectories run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-yowelix7taho'", Local "Local file system at /tmp/rclone3247573043", Modify Window "1ms" 2025/03/06 01:44:33 INFO : sub dir2: Making directory 2025/03/06 01:44:33 DEBUG : sub dir2/sub sub dir2: Making directory with metadata 2025/03/06 01:44:33 INFO : sub dir2/sub sub dir2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2025/03/06 01:44:33 DEBUG : Added delayed dir = "sub dir", newDst= 2025/03/06 01:44:33 DEBUG : Added delayed dir = "sub dir2", newDst= 2025/03/06 01:44:33 DEBUG : Added delayed dir = "sub dir2/sub sub dir2", newDst= 2025/03/06 01:44:33 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2025/03/06 01:44:33 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yowelix7taho': Waiting for checks to finish 2025/03/06 01:44:33 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yowelix7taho': Waiting for transfers to finish 2025/03/06 01:44:35 DEBUG : sub dir/hello world: md5 = 497c9c82758bd9e2f044755dad439db5 OK 2025/03/06 01:44:35 INFO : sub dir/hello world: Copied (new) 2025/03/06 01:44:36 INFO : sub dir: Set directory modification time (using DirSetModTime) 2025/03/06 01:44:38 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestCopyNoEmptyDirectories (5.33s) === RUN TestMoveEmptyDirectories run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-yowelix7taho'", Local "Local file system at /tmp/rclone3247573043", Modify Window "1ms" 2025/03/06 01:44:38 DEBUG : sub dir2: Making directory with metadata 2025/03/06 01:44:38 INFO : sub dir2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2025/03/06 01:44:39 DEBUG : sub dir: Making directory with metadata 2025/03/06 01:44:39 INFO : sub dir: Made directory with metadata (mtime=2025-03-06T01:44:38.838466682Z) 2025/03/06 01:44:39 DEBUG : sub dir2: Making directory with metadata 2025/03/06 01:44:40 INFO : sub dir2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2025/03/06 01:44:40 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2025/03/06 01:44:40 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yowelix7taho': Waiting for checks to finish 2025/03/06 01:44:40 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yowelix7taho': Waiting for transfers to finish 2025/03/06 01:44:42 DEBUG : sub dir/hello world: md5 = bd4d695688ebae0fa96d062751dafa09 OK 2025/03/06 01:44:42 INFO : sub dir/hello world: Copied (new) 2025/03/06 01:44:42 INFO : sub dir/hello world: Deleted run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-yowelix7taho'", Local "Local file system at /tmp/rclone3247573043", Modify Window "1ms" 2025/03/06 01:44:44 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestMoveEmptyDirectories (7.24s) === RUN TestSyncNoUpdateDirModtime run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-yowelix7taho'", Local "Local file system at /tmp/rclone3247573043", Modify Window "1ms" 2025/03/06 01:44:46 DEBUG : sub dir no update dir modtime: Making directory with metadata 2025/03/06 01:44:46 INFO : sub dir no update dir modtime: Made directory with metadata (mtime=2001-02-03T04:05:06.499999999Z) 2025/03/06 01:44:47 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yowelix7taho': Waiting for checks to finish 2025/03/06 01:44:47 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yowelix7taho': Waiting for transfers to finish 2025/03/06 01:44:47 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-yowelix7taho'", Local "Local file system at /tmp/rclone3247573043", Modify Window "1ms" --- PASS: TestSyncNoUpdateDirModtime (4.04s) === RUN TestMoveNoEmptyDirectories run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-yowelix7taho'", Local "Local file system at /tmp/rclone3247573043", Modify Window "1ms" 2025/03/06 01:44:50 INFO : sub dir2: Making directory 2025/03/06 01:44:50 DEBUG : Added delayed dir = "sub dir", newDst= 2025/03/06 01:44:50 DEBUG : Added delayed dir = "sub dir2", newDst= 2025/03/06 01:44:50 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2025/03/06 01:44:50 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yowelix7taho': Waiting for checks to finish 2025/03/06 01:44:50 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yowelix7taho': Waiting for transfers to finish 2025/03/06 01:44:52 DEBUG : sub dir/hello world: md5 = ec54a24b950612d0a9f0bd324f886ba1 OK 2025/03/06 01:44:52 INFO : sub dir/hello world: Copied (new) 2025/03/06 01:44:52 INFO : sub dir/hello world: Deleted 2025/03/06 01:44:53 INFO : sub dir: Set directory modification time (using DirSetModTime) 2025/03/06 01:44:54 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestMoveNoEmptyDirectories (5.43s) === RUN TestSyncEmptyDirectories run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-yowelix7taho'", Local "Local file system at /tmp/rclone3247573043", Modify Window "1ms" 2025/03/06 01:44:55 DEBUG : sub dir2: Making directory with metadata 2025/03/06 01:44:55 INFO : sub dir2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2025/03/06 01:44:55 INFO : sub dir: Set directory modification time (using DirSetModTime) 2025/03/06 01:44:55 DEBUG : sub dir: Making directory with metadata 2025/03/06 01:44:56 INFO : sub dir: Made directory with metadata (mtime=2001-02-03T04:05:06.499999999Z) 2025/03/06 01:44:56 DEBUG : sub dir2: Making directory with metadata 2025/03/06 01:44:57 INFO : sub dir2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2025/03/06 01:44:57 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2025/03/06 01:44:57 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yowelix7taho': Waiting for checks to finish 2025/03/06 01:44:57 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yowelix7taho': Waiting for transfers to finish 2025/03/06 01:44:58 DEBUG : sub dir/hello world: md5 = f4c796aaeeb595efbcc5c7c812296f9c OK 2025/03/06 01:44:58 INFO : sub dir/hello world: Copied (new) 2025/03/06 01:44:58 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-yowelix7taho'", Local "Local file system at /tmp/rclone3247573043", Modify Window "1ms" 2025/03/06 01:45:01 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestSyncEmptyDirectories (7.13s) === RUN TestSyncSetDelayedModTimes run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-yowelix7taho'", Local "Local file system at /tmp/rclone3247573043", Modify Window "1ms" sync_test.go:507: Backend doesn't have DirModTimeUpdatesOnWrite set --- SKIP: TestSyncSetDelayedModTimes (0.46s) === RUN TestSyncNoEmptyDirectories run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-yowelix7taho'", Local "Local file system at /tmp/rclone3247573043", Modify Window "1ms" 2025/03/06 01:45:03 INFO : sub dir2: Making directory 2025/03/06 01:45:03 DEBUG : Added delayed dir = "sub dir", newDst= 2025/03/06 01:45:03 DEBUG : Added delayed dir = "sub dir2", newDst= 2025/03/06 01:45:03 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2025/03/06 01:45:03 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yowelix7taho': Waiting for checks to finish 2025/03/06 01:45:03 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yowelix7taho': Waiting for transfers to finish 2025/03/06 01:45:05 DEBUG : sub dir/hello world: md5 = 5222dc182dec9bcf4af3399f4f50bb0d OK 2025/03/06 01:45:05 INFO : sub dir/hello world: Copied (new) 2025/03/06 01:45:05 DEBUG : Waiting for deletions to finish 2025/03/06 01:45:05 INFO : sub dir: Set directory modification time (using DirSetModTime) 2025/03/06 01:45:07 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestSyncNoEmptyDirectories (5.06s) === RUN TestServerSideCopy run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-yowelix7taho'", Local "Local file system at /tmp/rclone3247573043", Modify Window "1ms" 2025/03/06 01:45:10 DEBUG : sub dir/hello world: md5 = 3943b3abf00e2ccb366a2543ded2dcf9 OK 2025/03/06 01:45:10 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-xekufoy9qiqa" 2025/03/06 01:45:10 DEBUG : Creating backend with remote "TestDrive:crypt/5ciejd3rqlrnieh8jued4dnbn48eihfllafv6p0rrnldmh17r0l0" sync_test.go:590: Server side copy (if possible) Encrypted drive 'TestCryptDrive:rclone-test-yowelix7taho' -> Encrypted drive 'TestCryptDrive:rclone-test-xekufoy9qiqa' 2025/03/06 01:45:12 DEBUG : Added delayed dir = "sub dir", newDst= 2025/03/06 01:45:12 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2025/03/06 01:45:12 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-xekufoy9qiqa': Waiting for checks to finish 2025/03/06 01:45:12 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-xekufoy9qiqa': Waiting for transfers to finish 2025/03/06 01:45:14 INFO : sub dir/hello world: Copied (server-side copy) 2025/03/06 01:45:15 INFO : sub dir: Set directory modification time (using DirSetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-yowelix7taho'", Local "Local file system at /tmp/rclone3247573043", Modify Window "1ms" 2025/03/06 01:45:15 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-xekufoy9qiqa': Purge remote 2025/03/06 01:45:17 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestServerSideCopy (10.45s) === RUN TestCopyOverSelf run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-yowelix7taho'", Local "Local file system at /tmp/rclone3247573043", Modify Window "1ms" 2025/03/06 01:45:20 DEBUG : sub dir/hello world: md5 = 1a520a16f16101741ee41ee416e51482 OK 2025/03/06 01:45:22 INFO : sub dir: Set directory modification time (using SetModTime) 2025/03/06 01:45:22 DEBUG : Added delayed dir = "sub dir", newDst=sub dir 2025/03/06 01:45:22 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yowelix7taho': Waiting for checks to finish 2025/03/06 01:45:22 DEBUG : sub dir/hello world: Sizes differ (src 17 vs dst 11) 2025/03/06 01:45:22 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yowelix7taho': Waiting for transfers to finish 2025/03/06 01:45:23 DEBUG : sub dir/hello world: md5 = d12ac1bdaa430bc9397e698b5bc5671c OK 2025/03/06 01:45:23 INFO : sub dir/hello world: Copied (replaced existing) 2025/03/06 01:45:24 INFO : sub dir: Set directory modification time (using SetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-yowelix7taho'", Local "Local file system at /tmp/rclone3247573043", Modify Window "1ms" 2025/03/06 01:45:25 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestCopyOverSelf (8.22s) === RUN TestServerSideCopyOverSelf run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-yowelix7taho'", Local "Local file system at /tmp/rclone3247573043", Modify Window "1ms" 2025/03/06 01:45:29 DEBUG : sub dir/hello world: md5 = 1083db4a7ad52a89d8325e22e35fadf9 OK 2025/03/06 01:45:29 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-jujigug9xeno" 2025/03/06 01:45:29 DEBUG : Creating backend with remote "TestDrive:crypt/v3ifg6v2g5no5rufsq48fuc9tcap8dec5iv3bgotff0sk8v1hva0" sync_test.go:626: Server side copy (if possible) Encrypted drive 'TestCryptDrive:rclone-test-yowelix7taho' -> Encrypted drive 'TestCryptDrive:rclone-test-jujigug9xeno' 2025/03/06 01:45:30 DEBUG : Added delayed dir = "sub dir", newDst= 2025/03/06 01:45:30 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2025/03/06 01:45:30 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-jujigug9xeno': Waiting for checks to finish 2025/03/06 01:45:30 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-jujigug9xeno': Waiting for transfers to finish 2025/03/06 01:45:33 INFO : sub dir/hello world: Copied (server-side copy) 2025/03/06 01:45:33 INFO : sub dir: Set directory modification time (using DirSetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-yowelix7taho'", Local "Local file system at /tmp/rclone3247573043", Modify Window "1ms" 2025/03/06 01:45:35 DEBUG : sub dir/hello world: md5 = 35b59126e5659d37e0dad57881500ad8 OK 2025/03/06 01:45:36 DEBUG : sub dir: Directory modification time the same (differ by 0s, within tolerance 1ms) 2025/03/06 01:45:36 DEBUG : Added delayed dir = "sub dir", newDst=sub dir 2025/03/06 01:45:36 DEBUG : sub dir/hello world: Sizes differ (src 17 vs dst 11) 2025/03/06 01:45:36 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-jujigug9xeno': Waiting for checks to finish 2025/03/06 01:45:36 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-jujigug9xeno': Waiting for transfers to finish 2025/03/06 01:45:38 INFO : sub dir/hello world: Copied (server-side copy) 2025/03/06 01:45:38 INFO : sub dir: Set directory modification time (using SetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-yowelix7taho'", Local "Local file system at /tmp/rclone3247573043", Modify Window "1ms" 2025/03/06 01:45:39 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-jujigug9xeno': Purge remote 2025/03/06 01:45:40 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestServerSideCopyOverSelf (15.66s) === RUN TestMoveOverSelf run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-yowelix7taho'", Local "Local file system at /tmp/rclone3247573043", Modify Window "1ms" 2025/03/06 01:45:44 DEBUG : sub dir/hello world: md5 = 08dc084a3a4dc4f4e7d6f4b0b70e3870 OK 2025/03/06 01:45:45 INFO : sub dir: Set directory modification time (using SetModTime) 2025/03/06 01:45:45 DEBUG : Added delayed dir = "sub dir", newDst=sub dir 2025/03/06 01:45:45 DEBUG : sub dir/hello world: Sizes differ (src 17 vs dst 11) 2025/03/06 01:45:45 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yowelix7taho': Waiting for checks to finish 2025/03/06 01:45:45 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yowelix7taho': Waiting for transfers to finish 2025/03/06 01:45:47 DEBUG : sub dir/hello world: md5 = 681d619b45cde60c9cf0e479400334f5 OK 2025/03/06 01:45:47 INFO : sub dir/hello world: Copied (replaced existing) 2025/03/06 01:45:47 INFO : sub dir/hello world: Deleted 2025/03/06 01:45:47 INFO : sub dir: Set directory modification time (using SetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-yowelix7taho'", Local "Local file system at /tmp/rclone3247573043", Modify Window "1ms" 2025/03/06 01:45:49 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestMoveOverSelf (7.78s) === RUN TestServerSideMoveOverSelf run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-yowelix7taho'", Local "Local file system at /tmp/rclone3247573043", Modify Window "1ms" 2025/03/06 01:45:52 DEBUG : sub dir/hello world: md5 = 1b9cc8dd3a905e8dcc98aa5009c9cb22 OK 2025/03/06 01:45:52 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-kugohop1yadi" 2025/03/06 01:45:52 DEBUG : Creating backend with remote "TestDrive:crypt/o2djc1qrh0bcj4ukgrjj3arm3jqsotu5p82jpm7jiohea1ri4rb0" sync_test.go:671: Server side copy (if possible) Encrypted drive 'TestCryptDrive:rclone-test-yowelix7taho' -> Encrypted drive 'TestCryptDrive:rclone-test-kugohop1yadi' 2025/03/06 01:45:54 DEBUG : Added delayed dir = "sub dir", newDst= 2025/03/06 01:45:54 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2025/03/06 01:45:54 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-kugohop1yadi': Waiting for checks to finish 2025/03/06 01:45:54 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-kugohop1yadi': Waiting for transfers to finish 2025/03/06 01:45:56 INFO : sub dir/hello world: Copied (server-side copy) 2025/03/06 01:45:57 INFO : sub dir: Set directory modification time (using DirSetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-yowelix7taho'", Local "Local file system at /tmp/rclone3247573043", Modify Window "1ms" 2025/03/06 01:45:59 DEBUG : sub dir/hello world: md5 = 9ecea0a0ef285766af993b5b823c2176 OK 2025/03/06 01:45:59 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-kugohop1yadi': Using server-side directory move 2025/03/06 01:45:59 INFO : Encrypted drive 'TestCryptDrive:rclone-test-kugohop1yadi': Server side directory move failed - fallback to file moves: can't copy directory - destination already exists 2025/03/06 01:46:00 DEBUG : sub dir: Directory modification time the same (differ by 0s, within tolerance 1ms) 2025/03/06 01:46:00 DEBUG : Added delayed dir = "sub dir", newDst=sub dir 2025/03/06 01:46:00 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-kugohop1yadi': Waiting for checks to finish 2025/03/06 01:46:00 DEBUG : sub dir/hello world: Sizes differ (src 17 vs dst 11) 2025/03/06 01:46:00 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-kugohop1yadi': Waiting for transfers to finish 2025/03/06 01:46:00 INFO : sub dir/hello world: Deleted 2025/03/06 01:46:01 INFO : sub dir/hello world: Moved (server-side) 2025/03/06 01:46:01 INFO : sub dir: Set directory modification time (using SetModTime) 2025/03/06 01:46:04 DEBUG : sub dir/hello world: md5 = 3114b28bbf75964c3b464ffc3f1d5b26 OK 2025/03/06 01:46:04 DEBUG : testing file moves 2025/03/06 01:46:04 DEBUG : sub dir: Directory modification time the same (differ by 0s, within tolerance 1ms) 2025/03/06 01:46:04 DEBUG : Added delayed dir = "sub dir", newDst=sub dir 2025/03/06 01:46:05 DEBUG : sub dir/hello world: Sizes differ (src 24 vs dst 17) 2025/03/06 01:46:05 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-kugohop1yadi': Waiting for checks to finish 2025/03/06 01:46:05 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-kugohop1yadi': Waiting for transfers to finish 2025/03/06 01:46:05 INFO : sub dir/hello world: Deleted 2025/03/06 01:46:06 INFO : sub dir/hello world: Moved (server-side) 2025/03/06 01:46:06 INFO : sub dir: Set directory modification time (using SetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-yowelix7taho'", Local "Local file system at /tmp/rclone3247573043", Modify Window "1ms" 2025/03/06 01:46:07 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-kugohop1yadi': Purge remote --- PASS: TestServerSideMoveOverSelf (20.16s) === RUN TestCopyAfterDelete run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-yowelix7taho'", Local "Local file system at /tmp/rclone3247573043", Modify Window "1ms" 2025/03/06 01:46:12 DEBUG : sub dir/hello world: md5 = 148607042f31c57eae5648b3eaefe7e2 OK 2025/03/06 01:46:12 ERROR : : error listing: directory not found 2025/03/06 01:46:13 INFO : Local file system at /tmp/rclone3247573043: Making directory 2025/03/06 01:46:13 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yowelix7taho': Waiting for checks to finish 2025/03/06 01:46:13 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yowelix7taho': Waiting for transfers to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-yowelix7taho'", Local "Local file system at /tmp/rclone3247573043", Modify Window "1ms" 2025/03/06 01:46:15 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestCopyAfterDelete (5.98s) === RUN TestCopyRedownload run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-yowelix7taho'", Local "Local file system at /tmp/rclone3247573043", Modify Window "1ms" 2025/03/06 01:46:18 DEBUG : sub dir/hello world: md5 = d92c2dda93cc3767e90b5035ade7c768 OK 2025/03/06 01:46:19 DEBUG : Added delayed dir = "sub dir", newDst= 2025/03/06 01:46:19 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2025/03/06 01:46:19 DEBUG : Local file system at /tmp/rclone3247573043: Waiting for checks to finish 2025/03/06 01:46:19 DEBUG : Local file system at /tmp/rclone3247573043: Waiting for transfers to finish 2025/03/06 01:46:20 DEBUG : sub dir/hello world.285f0a30.partial: renamed to: sub dir/hello world 2025/03/06 01:46:20 INFO : sub dir/hello world: Copied (new) 2025/03/06 01:46:20 INFO : sub dir: Set directory modification time (using DirSetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-yowelix7taho'", Local "Local file system at /tmp/rclone3247573043", Modify Window "1ms" 2025/03/06 01:46:21 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestCopyRedownload (6.53s) === RUN TestSyncBasedOnCheckSum run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-yowelix7taho'", Local "Local file system at /tmp/rclone3247573043", Modify Window "1ms" 2025/03/06 01:46:23 DEBUG : check sum: Need to transfer - File not found at Destination 2025/03/06 01:46:23 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yowelix7taho': Waiting for checks to finish 2025/03/06 01:46:23 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yowelix7taho': Waiting for transfers to finish 2025/03/06 01:46:24 DEBUG : check sum: md5 = 7440d906f0d553135ec4303baeff6dcc OK 2025/03/06 01:46:24 INFO : check sum: Copied (new) 2025/03/06 01:46:24 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-yowelix7taho'", Local "Local file system at /tmp/rclone3247573043", Modify Window "1ms" 2025/03/06 01:46:25 NOTICE: Encrypted drive 'TestCryptDrive:rclone-test-yowelix7taho': --checksum is in use but the source and destination have no hashes in common; falling back to --size-only 2025/03/06 01:46:25 DEBUG : check sum: Size of src and dst objects identical 2025/03/06 01:46:25 DEBUG : check sum: Unchanged skipping 2025/03/06 01:46:25 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yowelix7taho': Waiting for checks to finish 2025/03/06 01:46:25 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yowelix7taho': Waiting for transfers to finish 2025/03/06 01:46:25 DEBUG : Waiting for deletions to finish 2025/03/06 01:46:25 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-yowelix7taho'", Local "Local file system at /tmp/rclone3247573043", Modify Window "1ms" --- PASS: TestSyncBasedOnCheckSum (4.16s) === RUN TestSyncSizeOnly run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-yowelix7taho'", Local "Local file system at /tmp/rclone3247573043", Modify Window "1ms" 2025/03/06 01:46:27 DEBUG : sizeonly: Need to transfer - File not found at Destination 2025/03/06 01:46:27 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yowelix7taho': Waiting for checks to finish 2025/03/06 01:46:27 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yowelix7taho': Waiting for transfers to finish 2025/03/06 01:46:28 DEBUG : sizeonly: md5 = 2230bf52cbd8b5f627c1f1c63149ac73 OK 2025/03/06 01:46:28 INFO : sizeonly: Copied (new) 2025/03/06 01:46:28 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-yowelix7taho'", Local "Local file system at /tmp/rclone3247573043", Modify Window "1ms" 2025/03/06 01:46:29 DEBUG : sizeonly: Sizes identical 2025/03/06 01:46:29 DEBUG : sizeonly: Unchanged skipping 2025/03/06 01:46:29 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yowelix7taho': Waiting for checks to finish 2025/03/06 01:46:29 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yowelix7taho': Waiting for transfers to finish 2025/03/06 01:46:29 DEBUG : Waiting for deletions to finish 2025/03/06 01:46:29 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-yowelix7taho'", Local "Local file system at /tmp/rclone3247573043", Modify Window "1ms" --- PASS: TestSyncSizeOnly (4.36s) === RUN TestSyncIgnoreSize run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-yowelix7taho'", Local "Local file system at /tmp/rclone3247573043", Modify Window "1ms" 2025/03/06 01:46:31 DEBUG : ignore-size: Need to transfer - File not found at Destination 2025/03/06 01:46:31 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yowelix7taho': Waiting for checks to finish 2025/03/06 01:46:31 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yowelix7taho': Waiting for transfers to finish 2025/03/06 01:46:33 DEBUG : ignore-size: md5 = 813ea6e00b8a8ee2b338297b118d21ed OK 2025/03/06 01:46:33 INFO : ignore-size: Copied (new) 2025/03/06 01:46:33 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-yowelix7taho'", Local "Local file system at /tmp/rclone3247573043", Modify Window "1ms" 2025/03/06 01:46:33 DEBUG : ignore-size: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/03/06 01:46:33 DEBUG : ignore-size: Unchanged skipping 2025/03/06 01:46:33 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yowelix7taho': Waiting for checks to finish 2025/03/06 01:46:33 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yowelix7taho': Waiting for transfers to finish 2025/03/06 01:46:33 DEBUG : Waiting for deletions to finish 2025/03/06 01:46:33 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-yowelix7taho'", Local "Local file system at /tmp/rclone3247573043", Modify Window "1ms" --- PASS: TestSyncIgnoreSize (4.27s) === RUN TestSyncIgnoreTimes run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-yowelix7taho'", Local "Local file system at /tmp/rclone3247573043", Modify Window "1ms" 2025/03/06 01:46:37 DEBUG : existing: md5 = 310f708db6b93994819e3923d01be16a OK 2025/03/06 01:46:37 DEBUG : existing: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/03/06 01:46:37 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yowelix7taho': Waiting for checks to finish 2025/03/06 01:46:37 DEBUG : existing: Unchanged skipping 2025/03/06 01:46:37 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yowelix7taho': Waiting for transfers to finish 2025/03/06 01:46:37 DEBUG : Waiting for deletions to finish 2025/03/06 01:46:37 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-yowelix7taho'", Local "Local file system at /tmp/rclone3247573043", Modify Window "1ms" 2025/03/06 01:46:37 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yowelix7taho': Waiting for checks to finish 2025/03/06 01:46:37 DEBUG : existing: Transferring unconditionally as --ignore-times is in use 2025/03/06 01:46:37 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yowelix7taho': Waiting for transfers to finish 2025/03/06 01:46:39 DEBUG : existing: md5 = c831eac93a65c67cc71fdd9f225f0985 OK 2025/03/06 01:46:39 INFO : existing: Copied (replaced existing) 2025/03/06 01:46:39 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-yowelix7taho'", Local "Local file system at /tmp/rclone3247573043", Modify Window "1ms" --- PASS: TestSyncIgnoreTimes (5.43s) === RUN TestSyncIgnoreExisting run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-yowelix7taho'", Local "Local file system at /tmp/rclone3247573043", Modify Window "1ms" 2025/03/06 01:46:41 DEBUG : existing: Need to transfer - File not found at Destination 2025/03/06 01:46:41 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yowelix7taho': Waiting for checks to finish 2025/03/06 01:46:41 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yowelix7taho': Waiting for transfers to finish 2025/03/06 01:46:42 DEBUG : existing: md5 = fc7c0b85038b1448ba31baa9c569763e OK 2025/03/06 01:46:42 INFO : existing: Copied (new) 2025/03/06 01:46:42 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-yowelix7taho'", Local "Local file system at /tmp/rclone3247573043", Modify Window "1ms" 2025/03/06 01:46:43 DEBUG : existing: Destination exists, skipping 2025/03/06 01:46:43 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yowelix7taho': Waiting for checks to finish 2025/03/06 01:46:43 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yowelix7taho': Waiting for transfers to finish 2025/03/06 01:46:43 DEBUG : Waiting for deletions to finish 2025/03/06 01:46:43 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-yowelix7taho'", Local "Local file system at /tmp/rclone3247573043", Modify Window "1ms" --- PASS: TestSyncIgnoreExisting (4.10s) === RUN TestSyncIgnoreErrors run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-yowelix7taho'", Local "Local file system at /tmp/rclone3247573043", Modify Window "1ms" 2025/03/06 01:46:47 DEBUG : b/potato: md5 = 7bd1d428dea383ce54103ab70920cb79 OK 2025/03/06 01:46:49 DEBUG : c/non empty space: md5 = e9ad1dc1dabbd7295212787505f6f8f2 OK 2025/03/06 01:46:49 INFO : d: Making directory 2025/03/06 01:46:51 DEBUG : Added delayed dir = "a", newDst= 2025/03/06 01:46:51 INFO : c: Set directory modification time (using SetModTime) 2025/03/06 01:46:51 DEBUG : Added delayed dir = "c", newDst=c 2025/03/06 01:46:51 DEBUG : a/potato2: Need to transfer - File not found at Destination 2025/03/06 01:46:51 DEBUG : c/non empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/03/06 01:46:51 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yowelix7taho': Waiting for checks to finish 2025/03/06 01:46:51 DEBUG : c/non empty space: Unchanged skipping 2025/03/06 01:46:51 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yowelix7taho': Waiting for transfers to finish 2025/03/06 01:46:53 DEBUG : a/potato2: md5 = bafcb6f2a0a8378e279ac9dd64c4b2ce OK 2025/03/06 01:46:53 INFO : a/potato2: Copied (new) 2025/03/06 01:46:53 DEBUG : Waiting for deletions to finish 2025/03/06 01:46:54 INFO : b/potato: Deleted 2025/03/06 01:46:54 INFO : a: Set directory modification time (using DirSetModTime) 2025/03/06 01:46:54 INFO : d: Removing directory 2025/03/06 01:46:55 INFO : b: Removing directory 2025/03/06 01:46:55 DEBUG : 32d8ua6196mc1r7qkfog53rkg0: Rmdir: contains trashed file: "2m507n64kafsi59v9q71r281a4" 2025/03/06 01:46:56 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yowelix7taho': deleted 2 directories run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-yowelix7taho'", Local "Local file system at /tmp/rclone3247573043", Modify Window "1ms" 2025/03/06 01:46:58 DEBUG : 3i9du405pfogq3ncai6pg7ouio: Rmdir: contains trashed file: "982d3pss7t5pn0il16r2foj31s" 2025/03/06 01:46:59 DEBUG : 2bsvlrk2ne1lfitm6tttcu0qt8: Rmdir: contains trashed file: "89l8renevh3mji1c8r1p7qn6tg" --- PASS: TestSyncIgnoreErrors (14.86s) === RUN TestSyncAfterChangingModtimeOnly run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-yowelix7taho'", Local "Local file system at /tmp/rclone3247573043", Modify Window "1ms" 2025/03/06 01:47:01 DEBUG : empty space: md5 = 79796a41d9a0cb1c2ec2d4ab08efdda5 OK 2025/03/06 01:47:01 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yowelix7taho': Waiting for checks to finish 2025/03/06 01:47:01 DEBUG : empty space: Modification times differ by -95456h54m52.624456789s: 2011-12-25 12:59:59.123456789 +0000 UTC, 2001-02-03 04:05:06.499 +0000 UTC 2025/03/06 01:47:01 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yowelix7taho': Waiting for transfers to finish 2025/03/06 01:47:01 NOTICE: empty space: Skipped copy as --dry-run is set (size 1) 2025/03/06 01:47:01 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-yowelix7taho'", Local "Local file system at /tmp/rclone3247573043", Modify Window "1ms" 2025/03/06 01:47:02 DEBUG : empty space: Modification times differ by -95456h54m52.624456789s: 2011-12-25 12:59:59.123456789 +0000 UTC, 2001-02-03 04:05:06.499 +0000 UTC 2025/03/06 01:47:02 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yowelix7taho': Waiting for checks to finish 2025/03/06 01:47:02 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yowelix7taho': Waiting for transfers to finish 2025/03/06 01:47:03 DEBUG : empty space: md5 = 15224859e978897d21bd5b9417404aee OK 2025/03/06 01:47:03 INFO : empty space: Copied (replaced existing) 2025/03/06 01:47:03 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-yowelix7taho'", Local "Local file system at /tmp/rclone3247573043", Modify Window "1ms" --- PASS: TestSyncAfterChangingModtimeOnly (5.65s) === RUN TestSyncAfterChangingModtimeOnlyWithNoUpdateModTime run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-yowelix7taho'", Local "Local file system at /tmp/rclone3247573043", Modify Window "1ms" sync_test.go:1016: Can't check this if no hashes supported --- PASS: TestSyncAfterChangingModtimeOnlyWithNoUpdateModTime (0.48s) === RUN TestSyncDoesntUpdateModtime run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-yowelix7taho'", Local "Local file system at /tmp/rclone3247573043", Modify Window "1ms" 2025/03/06 01:47:07 DEBUG : foo: md5 = ff5946f7c675dbd94bd6b33e827cae06 OK 2025/03/06 01:47:08 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yowelix7taho': Waiting for checks to finish 2025/03/06 01:47:08 DEBUG : foo: Modification times differ by -95456h54m52.624456789s: 2011-12-25 12:59:59.123456789 +0000 UTC, 2001-02-03 04:05:06.499 +0000 UTC 2025/03/06 01:47:08 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yowelix7taho': Waiting for transfers to finish 2025/03/06 01:47:09 DEBUG : foo: md5 = ef0b9329b448ad594e56c0dce12a5270 OK 2025/03/06 01:47:09 INFO : foo: Copied (replaced existing) 2025/03/06 01:47:09 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-yowelix7taho'", Local "Local file system at /tmp/rclone3247573043", Modify Window "1ms" --- PASS: TestSyncDoesntUpdateModtime (4.66s) === RUN TestSyncAfterAddingAFile run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-yowelix7taho'", Local "Local file system at /tmp/rclone3247573043", Modify Window "1ms" 2025/03/06 01:47:12 DEBUG : empty space: md5 = 1fbe500018fb3a93e18aec7df238d180 OK 2025/03/06 01:47:12 DEBUG : potato: Need to transfer - File not found at Destination 2025/03/06 01:47:12 DEBUG : empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/03/06 01:47:12 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yowelix7taho': Waiting for checks to finish 2025/03/06 01:47:12 DEBUG : empty space: Unchanged skipping 2025/03/06 01:47:12 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yowelix7taho': Waiting for transfers to finish 2025/03/06 01:47:14 DEBUG : potato: md5 = c1f9bb4c447bd036a9fd621e2927983c OK 2025/03/06 01:47:14 INFO : potato: Copied (new) 2025/03/06 01:47:14 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-yowelix7taho'", Local "Local file system at /tmp/rclone3247573043", Modify Window "1ms" --- PASS: TestSyncAfterAddingAFile (5.29s) === RUN TestSyncAfterChangingFilesSizeOnly run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-yowelix7taho'", Local "Local file system at /tmp/rclone3247573043", Modify Window "1ms" 2025/03/06 01:47:17 DEBUG : potato: md5 = a0f6bce655bde635d9cbcbe4bef3c1fb OK 2025/03/06 01:47:17 DEBUG : potato: Sizes differ (src 21 vs dst 60) 2025/03/06 01:47:17 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yowelix7taho': Waiting for checks to finish 2025/03/06 01:47:17 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yowelix7taho': Waiting for transfers to finish 2025/03/06 01:47:19 DEBUG : potato: md5 = 7d892a9fe69463631a8ef36de4724250 OK 2025/03/06 01:47:19 INFO : potato: Copied (replaced existing) 2025/03/06 01:47:19 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-yowelix7taho'", Local "Local file system at /tmp/rclone3247573043", Modify Window "1ms" --- PASS: TestSyncAfterChangingFilesSizeOnly (4.58s) === RUN TestSyncAfterChangingContentsOnly run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-yowelix7taho'", Local "Local file system at /tmp/rclone3247573043", Modify Window "1ms" 2025/03/06 01:47:22 DEBUG : potato: md5 = 7da0b53a3f7b19ed55dcdb7fa5e35dc4 OK 2025/03/06 01:47:22 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yowelix7taho': Waiting for checks to finish 2025/03/06 01:47:22 DEBUG : potato: Modification times differ by 119h59m59.876543211s: 2011-12-25 12:59:59.123456789 +0000 UTC, 2011-12-30 12:59:59 +0000 UTC 2025/03/06 01:47:22 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yowelix7taho': Waiting for transfers to finish 2025/03/06 01:47:24 DEBUG : potato: md5 = c06e4ebcf45153131ca06a148b69b01c OK 2025/03/06 01:47:24 INFO : potato: Copied (replaced existing) 2025/03/06 01:47:24 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-yowelix7taho'", Local "Local file system at /tmp/rclone3247573043", Modify Window "1ms" --- PASS: TestSyncAfterChangingContentsOnly (4.93s) === RUN TestSyncAfterRemovingAFileAndAddingAFileDryRun run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-yowelix7taho'", Local "Local file system at /tmp/rclone3247573043", Modify Window "1ms" 2025/03/06 01:47:27 DEBUG : potato: md5 = 0bed85e910acdfbd47842f2d2b12d430 OK 2025/03/06 01:47:28 DEBUG : empty space: md5 = d4d03f437b1d109b2afcae559846e5ed OK 2025/03/06 01:47:28 DEBUG : potato2: Need to transfer - File not found at Destination 2025/03/06 01:47:28 NOTICE: potato2: Skipped copy as --dry-run is set (size 60) 2025/03/06 01:47:28 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yowelix7taho': Waiting for checks to finish 2025/03/06 01:47:28 DEBUG : empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/03/06 01:47:28 DEBUG : empty space: Unchanged skipping 2025/03/06 01:47:28 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yowelix7taho': Waiting for transfers to finish 2025/03/06 01:47:28 DEBUG : Waiting for deletions to finish 2025/03/06 01:47:28 NOTICE: potato: Skipped delete as --dry-run is set (size 21) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-yowelix7taho'", Local "Local file system at /tmp/rclone3247573043", Modify Window "1ms" --- PASS: TestSyncAfterRemovingAFileAndAddingAFileDryRun (5.19s) === RUN TestSyncAfterRemovingAFileAndAddingAFile run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-yowelix7taho'", Local "Local file system at /tmp/rclone3247573043", Modify Window "1ms" 2025/03/06 01:47:32 DEBUG : potato: md5 = 3a7bff556d11b692a496e9b87aff170d OK 2025/03/06 01:47:33 DEBUG : empty space: md5 = 2bd133c1546e33b64c9febd9427e0dc5 OK 2025/03/06 01:47:34 DEBUG : potato2: Need to transfer - File not found at Destination 2025/03/06 01:47:34 DEBUG : empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/03/06 01:47:34 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yowelix7taho': Waiting for checks to finish 2025/03/06 01:47:34 DEBUG : empty space: Unchanged skipping 2025/03/06 01:47:34 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yowelix7taho': Waiting for transfers to finish 2025/03/06 01:47:35 DEBUG : potato2: md5 = cac163e865e0cf3e936962b9b6b2b111 OK 2025/03/06 01:47:35 INFO : potato2: Copied (new) 2025/03/06 01:47:35 DEBUG : Waiting for deletions to finish 2025/03/06 01:47:35 INFO : potato: Deleted run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-yowelix7taho'", Local "Local file system at /tmp/rclone3247573043", Modify Window "1ms" --- PASS: TestSyncAfterRemovingAFileAndAddingAFile (7.01s) === RUN TestSyncAfterRemovingAFileAndAddingAFileSubDir run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-yowelix7taho'", Local "Local file system at /tmp/rclone3247573043", Modify Window "1ms" 2025/03/06 01:47:40 DEBUG : b/potato: md5 = 33d152c875cc79365951cb4556f5abc4 OK 2025/03/06 01:47:42 DEBUG : c/non empty space: md5 = 35ccbe17582acbdac1946e298710be5c OK 2025/03/06 01:47:42 INFO : d: Making directory 2025/03/06 01:47:42 INFO : d/e: Making directory 2025/03/06 01:47:44 DEBUG : Added delayed dir = "a", newDst= 2025/03/06 01:47:45 INFO : c: Set directory modification time (using SetModTime) 2025/03/06 01:47:45 DEBUG : Added delayed dir = "c", newDst=c 2025/03/06 01:47:45 DEBUG : a/potato2: Need to transfer - File not found at Destination 2025/03/06 01:47:45 DEBUG : c/non empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/03/06 01:47:45 DEBUG : c/non empty space: Unchanged skipping 2025/03/06 01:47:46 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yowelix7taho': Waiting for checks to finish 2025/03/06 01:47:46 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yowelix7taho': Waiting for transfers to finish 2025/03/06 01:47:47 DEBUG : a/potato2: md5 = 67369eb77ccceb40efaae9bc5b10c598 OK 2025/03/06 01:47:47 INFO : a/potato2: Copied (new) 2025/03/06 01:47:47 DEBUG : Waiting for deletions to finish 2025/03/06 01:47:47 INFO : b/potato: Deleted 2025/03/06 01:47:48 INFO : a: Set directory modification time (using DirSetModTime) 2025/03/06 01:47:48 INFO : d/e: Removing directory 2025/03/06 01:47:48 INFO : d: Removing directory 2025/03/06 01:47:49 DEBUG : ka6id8d20d3s5ktapedlphgta8: Rmdir: contains trashed file: "r8sppajuabeak3sbgj2ak8vuf8" 2025/03/06 01:47:49 INFO : b: Removing directory 2025/03/06 01:47:49 DEBUG : 32d8ua6196mc1r7qkfog53rkg0: Rmdir: contains trashed file: "2m507n64kafsi59v9q71r281a4" 2025/03/06 01:47:50 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yowelix7taho': deleted 3 directories run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-yowelix7taho'", Local "Local file system at /tmp/rclone3247573043", Modify Window "1ms" 2025/03/06 01:47:52 DEBUG : 3i9du405pfogq3ncai6pg7ouio: Rmdir: contains trashed file: "982d3pss7t5pn0il16r2foj31s" 2025/03/06 01:47:53 DEBUG : 2bsvlrk2ne1lfitm6tttcu0qt8: Rmdir: contains trashed file: "89l8renevh3mji1c8r1p7qn6tg" --- PASS: TestSyncAfterRemovingAFileAndAddingAFileSubDir (16.59s) === RUN TestSyncAfterRemovingAFileAndAddingAFileSubDirWithErrors run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-yowelix7taho'", Local "Local file system at /tmp/rclone3247573043", Modify Window "1ms" 2025/03/06 01:47:56 DEBUG : b/potato: md5 = 1f0347d2f0c084743247bc961e20545c OK 2025/03/06 01:47:58 DEBUG : c/non empty space: md5 = 49ff190ceae3d4a36c1f1d8350552627 OK 2025/03/06 01:47:58 INFO : d: Making directory 2025/03/06 01:48:00 DEBUG : Added delayed dir = "a", newDst= 2025/03/06 01:48:00 INFO : c: Set directory modification time (using SetModTime) 2025/03/06 01:48:00 DEBUG : Added delayed dir = "c", newDst=c 2025/03/06 01:48:00 DEBUG : a/potato2: Need to transfer - File not found at Destination 2025/03/06 01:48:00 DEBUG : c/non empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/03/06 01:48:00 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yowelix7taho': Waiting for checks to finish 2025/03/06 01:48:00 DEBUG : c/non empty space: Unchanged skipping 2025/03/06 01:48:00 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yowelix7taho': Waiting for transfers to finish 2025/03/06 01:48:02 DEBUG : a/potato2: md5 = 280079b323a0b036f189b4c22f539d31 OK 2025/03/06 01:48:02 INFO : a/potato2: Copied (new) 2025/03/06 01:48:02 ERROR : Encrypted drive 'TestCryptDrive:rclone-test-yowelix7taho': not deleting files as there were IO errors 2025/03/06 01:48:03 INFO : a: Set directory modification time (using DirSetModTime) 2025/03/06 01:48:03 ERROR : Encrypted drive 'TestCryptDrive:rclone-test-yowelix7taho': not deleting directories as there were IO errors run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-yowelix7taho'", Local "Local file system at /tmp/rclone3247573043", Modify Window "1ms" 2025/03/06 01:48:06 DEBUG : 3i9du405pfogq3ncai6pg7ouio: Rmdir: contains trashed file: "982d3pss7t5pn0il16r2foj31s" 2025/03/06 01:48:07 DEBUG : 32d8ua6196mc1r7qkfog53rkg0: Rmdir: contains trashed file: "2m507n64kafsi59v9q71r281a4" 2025/03/06 01:48:07 DEBUG : 2bsvlrk2ne1lfitm6tttcu0qt8: Rmdir: contains trashed file: "89l8renevh3mji1c8r1p7qn6tg" --- PASS: TestSyncAfterRemovingAFileAndAddingAFileSubDirWithErrors (14.65s) === RUN TestSyncDeleteAfter --- PASS: TestSyncDeleteAfter (0.00s) === RUN TestSyncDeleteDuring run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-yowelix7taho'", Local "Local file system at /tmp/rclone3247573043", Modify Window "1ms" 2025/03/06 01:48:10 DEBUG : potato: md5 = ea4d4ddce7a943528a2220daa867cd85 OK 2025/03/06 01:48:11 DEBUG : empty space: md5 = 25ae4b8869352ed8e3d3d6efd01f40a7 OK 2025/03/06 01:48:12 DEBUG : Waiting for deletions to finish 2025/03/06 01:48:12 DEBUG : potato2: Need to transfer - File not found at Destination 2025/03/06 01:48:12 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yowelix7taho': Waiting for checks to finish 2025/03/06 01:48:12 DEBUG : empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/03/06 01:48:12 DEBUG : empty space: Unchanged skipping 2025/03/06 01:48:12 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yowelix7taho': Waiting for transfers to finish 2025/03/06 01:48:12 INFO : potato: Deleted 2025/03/06 01:48:13 DEBUG : potato2: md5 = 48323da78c32ae075b69ca45338154e7 OK 2025/03/06 01:48:13 INFO : potato2: Copied (new) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-yowelix7taho'", Local "Local file system at /tmp/rclone3247573043", Modify Window "1ms" --- PASS: TestSyncDeleteDuring (7.97s) === RUN TestSyncDeleteBefore run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-yowelix7taho'", Local "Local file system at /tmp/rclone3247573043", Modify Window "1ms" 2025/03/06 01:48:18 DEBUG : potato: md5 = ea7e1aa4eb980b82e7370378103bfe96 OK 2025/03/06 01:48:19 DEBUG : empty space: md5 = 6b13f944d441cb227c28af12fdcc3d12 OK 2025/03/06 01:48:19 DEBUG : Waiting for deletions to finish 2025/03/06 01:48:20 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yowelix7taho': Waiting for checks to finish 2025/03/06 01:48:20 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yowelix7taho': Waiting for transfers to finish 2025/03/06 01:48:20 INFO : potato: Deleted 2025/03/06 01:48:20 DEBUG : potato2: Need to transfer - File not found at Destination 2025/03/06 01:48:20 DEBUG : empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/03/06 01:48:20 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yowelix7taho': Waiting for checks to finish 2025/03/06 01:48:20 DEBUG : empty space: Unchanged skipping 2025/03/06 01:48:20 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yowelix7taho': Waiting for transfers to finish 2025/03/06 01:48:22 DEBUG : potato2: md5 = cdca134eab11ea06f63764d624333fa4 OK 2025/03/06 01:48:22 INFO : potato2: Copied (new) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-yowelix7taho'", Local "Local file system at /tmp/rclone3247573043", Modify Window "1ms" --- PASS: TestSyncDeleteBefore (7.35s) === RUN TestCopyDeleteBefore run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-yowelix7taho'", Local "Local file system at /tmp/rclone3247573043", Modify Window "1ms" 2025/03/06 01:48:25 DEBUG : potato: md5 = 5849106ac8fb884e726d96982b344ae9 OK 2025/03/06 01:48:26 DEBUG : potato2: Need to transfer - File not found at Destination 2025/03/06 01:48:26 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yowelix7taho': Waiting for checks to finish 2025/03/06 01:48:26 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yowelix7taho': Waiting for transfers to finish 2025/03/06 01:48:27 DEBUG : potato2: md5 = ba02d5b629f68b7ef26907e58e484a97 OK 2025/03/06 01:48:27 INFO : potato2: Copied (new) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-yowelix7taho'", Local "Local file system at /tmp/rclone3247573043", Modify Window "1ms" --- PASS: TestCopyDeleteBefore (5.35s) === RUN TestSyncWithExclude run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-yowelix7taho'", Local "Local file system at /tmp/rclone3247573043", Modify Window "1ms" 2025/03/06 01:48:31 DEBUG : potato2: md5 = 6b7f26501a87097e8e085e8a3e5a4ed8 OK 2025/03/06 01:48:32 DEBUG : empty space: md5 = 5c51c55dce53c7722f7f349208184569 OK 2025/03/06 01:48:33 DEBUG : enormous: Excluded (Size Filter) 2025/03/06 01:48:33 DEBUG : enormous: Excluded 2025/03/06 01:48:33 DEBUG : potato2: Excluded (Size Filter) 2025/03/06 01:48:33 DEBUG : potato2: Excluded 2025/03/06 01:48:33 DEBUG : potato2: Excluded (Size Filter) 2025/03/06 01:48:33 DEBUG : potato2: Excluded 2025/03/06 01:48:33 DEBUG : empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/03/06 01:48:33 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yowelix7taho': Waiting for checks to finish 2025/03/06 01:48:33 DEBUG : empty space: Unchanged skipping 2025/03/06 01:48:33 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yowelix7taho': Waiting for transfers to finish 2025/03/06 01:48:33 DEBUG : Waiting for deletions to finish 2025/03/06 01:48:33 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-yowelix7taho'", Local "Local file system at /tmp/rclone3247573043", Modify Window "1ms" 2025/03/06 01:48:33 DEBUG : enormous: Excluded (Size Filter) 2025/03/06 01:48:33 DEBUG : enormous: Excluded 2025/03/06 01:48:33 DEBUG : potato2: Excluded (Size Filter) 2025/03/06 01:48:33 DEBUG : potato2: Excluded 2025/03/06 01:48:33 DEBUG : potato2: Excluded (Size Filter) 2025/03/06 01:48:33 DEBUG : potato2: Excluded 2025/03/06 01:48:33 DEBUG : Local file system at /tmp/rclone3247573043: Waiting for checks to finish 2025/03/06 01:48:33 DEBUG : empty space: Size and modification time the same (differ by 456.789µs, within tolerance 1ms) 2025/03/06 01:48:33 DEBUG : empty space: Unchanged skipping 2025/03/06 01:48:33 DEBUG : Local file system at /tmp/rclone3247573043: Waiting for transfers to finish 2025/03/06 01:48:33 DEBUG : Waiting for deletions to finish 2025/03/06 01:48:33 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-yowelix7taho'", Local "Local file system at /tmp/rclone3247573043", Modify Window "1ms" --- PASS: TestSyncWithExclude (6.17s) === RUN TestSyncWithExcludeAndDeleteExcluded run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-yowelix7taho'", Local "Local file system at /tmp/rclone3247573043", Modify Window "1ms" 2025/03/06 01:48:37 DEBUG : potato2: md5 = 040f514906d12e703b43e0c84d3d662f OK 2025/03/06 01:48:38 DEBUG : empty space: md5 = e6d6739addf57ab5750f3360a6e11c58 OK 2025/03/06 01:48:40 DEBUG : enormous: md5 = 80765f2266aacc4b72e1148f46294e40 OK 2025/03/06 01:48:40 DEBUG : enormous: Excluded (Size Filter) 2025/03/06 01:48:40 DEBUG : enormous: Excluded 2025/03/06 01:48:40 DEBUG : potato2: Excluded (Size Filter) 2025/03/06 01:48:40 DEBUG : potato2: Excluded 2025/03/06 01:48:40 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yowelix7taho': Waiting for checks to finish 2025/03/06 01:48:40 DEBUG : empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/03/06 01:48:40 DEBUG : empty space: Unchanged skipping 2025/03/06 01:48:40 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yowelix7taho': Waiting for transfers to finish 2025/03/06 01:48:40 DEBUG : Waiting for deletions to finish 2025/03/06 01:48:41 INFO : potato2: Deleted 2025/03/06 01:48:41 INFO : enormous: Deleted 2025/03/06 01:48:41 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-yowelix7taho'", Local "Local file system at /tmp/rclone3247573043", Modify Window "1ms" 2025/03/06 01:48:41 DEBUG : Local file system at /tmp/rclone3247573043: Waiting for checks to finish 2025/03/06 01:48:41 DEBUG : empty space: Size and modification time the same (differ by 456.789µs, within tolerance 1ms) 2025/03/06 01:48:41 DEBUG : empty space: Unchanged skipping 2025/03/06 01:48:41 DEBUG : Local file system at /tmp/rclone3247573043: Waiting for transfers to finish 2025/03/06 01:48:41 DEBUG : Waiting for deletions to finish 2025/03/06 01:48:41 INFO : enormous: Deleted 2025/03/06 01:48:41 INFO : potato2: Deleted 2025/03/06 01:48:41 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-yowelix7taho'", Local "Local file system at /tmp/rclone3247573043", Modify Window "1ms" --- PASS: TestSyncWithExcludeAndDeleteExcluded (7.52s) === RUN TestSyncWithUpdateOlder run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-yowelix7taho'", Local "Local file system at /tmp/rclone3247573043", Modify Window "1ms" 2025/03/06 01:48:44 DEBUG : one: md5 = 817b4c8b1a2ebf1c8aed0f07246132d6 OK 2025/03/06 01:48:46 DEBUG : two: md5 = 3adaa655c77925e9e025503036a2dcbc OK 2025/03/06 01:48:47 DEBUG : three: md5 = 2e51bfda6cf3897ed5b2a413d10e8b18 OK 2025/03/06 01:48:48 DEBUG : four: md5 = ecd64a790a920500de345fc1d0325f04 OK 2025/03/06 01:48:49 DEBUG : five: Need to transfer - File not found at Destination 2025/03/06 01:48:49 DEBUG : four: Sizes differ (src 4 vs dst 8) 2025/03/06 01:48:49 DEBUG : one: Destination is newer than source, skipping 2025/03/06 01:48:49 DEBUG : three: Sizes identical 2025/03/06 01:48:49 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yowelix7taho': Waiting for checks to finish 2025/03/06 01:48:49 DEBUG : four: Destination mod time is within 1s of source but files differ, transferring 2025/03/06 01:48:49 DEBUG : three: Destination mod time is within 1s of source and files identical, skipping 2025/03/06 01:48:49 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yowelix7taho': Waiting for transfers to finish 2025/03/06 01:48:50 DEBUG : four: md5 = 51e7963db66e9484a2f94a886aeb719b OK 2025/03/06 01:48:50 INFO : four: Copied (replaced existing) 2025/03/06 01:48:50 DEBUG : five: md5 = 2d60844ba4d043b3ac3b47628d59d23f OK 2025/03/06 01:48:50 INFO : five: Copied (new) 2025/03/06 01:48:50 DEBUG : two: md5 = 30149f71fc77aaf85c214f910c2ea78d OK 2025/03/06 01:48:50 INFO : two: Copied (replaced existing) 2025/03/06 01:48:50 DEBUG : Waiting for deletions to finish sync_test.go:1449: Skip test with --checksum as no hashes supported --- PASS: TestSyncWithUpdateOlder (10.21s) === 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-yowelix7taho'", Local "Local file system at /tmp/rclone3247573043", Modify Window "1ms" sync_test.go:1538: Can track renames: false 2025/03/06 01:48:53 ERROR : Encrypted drive 'TestCryptDrive:rclone-test-yowelix7taho': Ignoring --track-renames as the source and destination do not have a common hash 2025/03/06 01:48:53 DEBUG : potato: Need to transfer - File not found at Destination 2025/03/06 01:48:53 DEBUG : yam: Need to transfer - File not found at Destination 2025/03/06 01:48:53 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yowelix7taho': Waiting for checks to finish 2025/03/06 01:48:53 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yowelix7taho': Waiting for transfers to finish 2025/03/06 01:48:55 DEBUG : yam: md5 = 78e00c95c8bbafc1ee202a9412e80bfa OK 2025/03/06 01:48:55 INFO : yam: Copied (new) 2025/03/06 01:48:55 DEBUG : potato: md5 = 546c13254cdaaa38622cfea02d2c59c2 OK 2025/03/06 01:48:55 INFO : potato: Copied (new) 2025/03/06 01:48:55 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-yowelix7taho'", Local "Local file system at /tmp/rclone3247573043", Modify Window "1ms" 2025/03/06 01:48:55 ERROR : Encrypted drive 'TestCryptDrive:rclone-test-yowelix7taho': Ignoring --track-renames as the source and destination do not have a common hash 2025/03/06 01:48:55 DEBUG : yaml: Need to transfer - File not found at Destination 2025/03/06 01:48:55 DEBUG : potato: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/03/06 01:48:55 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yowelix7taho': Waiting for checks to finish 2025/03/06 01:48:55 DEBUG : potato: Unchanged skipping 2025/03/06 01:48:55 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yowelix7taho': Waiting for transfers to finish 2025/03/06 01:48:57 DEBUG : yaml: md5 = e36de1aab9d65b1750eff4685e776dd2 OK 2025/03/06 01:48:57 INFO : yaml: Copied (new) 2025/03/06 01:48:57 DEBUG : Waiting for deletions to finish 2025/03/06 01:48:57 INFO : yam: Deleted run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-yowelix7taho'", Local "Local file system at /tmp/rclone3247573043", Modify Window "1ms" --- PASS: TestSyncWithTrackRenames (6.36s) === RUN TestParseRenamesStrategyModtime --- PASS: TestParseRenamesStrategyModtime (0.00s) === RUN TestRenamesStrategyModtime --- PASS: TestRenamesStrategyModtime (0.00s) === RUN TestSyncWithTrackRenamesStrategyModtime run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-yowelix7taho'", Local "Local file system at /tmp/rclone3247573043", Modify Window "1ms" sync_test.go:1610: Can track renames: true 2025/03/06 01:49:00 INFO : Encrypted drive 'TestCryptDrive:rclone-test-yowelix7taho': Making map for --track-renames 2025/03/06 01:49:00 INFO : Encrypted drive 'TestCryptDrive:rclone-test-yowelix7taho': Finished making map for --track-renames 2025/03/06 01:49:00 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yowelix7taho': Waiting for checks to finish 2025/03/06 01:49:00 DEBUG : yam: Need to transfer - No matching file found at Destination 2025/03/06 01:49:00 DEBUG : potato: Need to transfer - No matching file found at Destination 2025/03/06 01:49:00 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yowelix7taho': Waiting for renames to finish 2025/03/06 01:49:00 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yowelix7taho': Waiting for transfers to finish 2025/03/06 01:49:01 DEBUG : yam: md5 = 42df14a26d3a5e2e7858757458be0744 OK 2025/03/06 01:49:01 INFO : yam: Copied (new) 2025/03/06 01:49:01 DEBUG : potato: md5 = 7ba7e7e44e3243f2099c2dbe8d026ad2 OK 2025/03/06 01:49:01 INFO : potato: Copied (new) 2025/03/06 01:49:01 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-yowelix7taho'", Local "Local file system at /tmp/rclone3247573043", Modify Window "1ms" 2025/03/06 01:49:02 DEBUG : potato: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/03/06 01:49:02 INFO : Encrypted drive 'TestCryptDrive:rclone-test-yowelix7taho': Making map for --track-renames 2025/03/06 01:49:02 INFO : Encrypted drive 'TestCryptDrive:rclone-test-yowelix7taho': Finished making map for --track-renames 2025/03/06 01:49:02 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yowelix7taho': Waiting for checks to finish 2025/03/06 01:49:02 DEBUG : potato: Unchanged skipping 2025/03/06 01:49:02 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yowelix7taho': Waiting for renames to finish 2025/03/06 01:49:03 INFO : yam: Moved (server-side) to: yaml 2025/03/06 01:49:03 INFO : yaml: Renamed from "yam" 2025/03/06 01:49:03 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yowelix7taho': Waiting for transfers to finish 2025/03/06 01:49:03 DEBUG : Waiting for deletions to finish 2025/03/06 01:49:03 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-yowelix7taho'", Local "Local file system at /tmp/rclone3247573043", Modify Window "1ms" --- PASS: TestSyncWithTrackRenamesStrategyModtime (5.44s) === RUN TestSyncWithTrackRenamesStrategyLeaf run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-yowelix7taho'", Local "Local file system at /tmp/rclone3247573043", Modify Window "1ms" sync_test.go:1649: Can track renames: true 2025/03/06 01:49:05 DEBUG : Added delayed dir = "sub", newDst= 2025/03/06 01:49:05 INFO : Encrypted drive 'TestCryptDrive:rclone-test-yowelix7taho': Making map for --track-renames 2025/03/06 01:49:05 INFO : Encrypted drive 'TestCryptDrive:rclone-test-yowelix7taho': Finished making map for --track-renames 2025/03/06 01:49:05 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yowelix7taho': Waiting for checks to finish 2025/03/06 01:49:05 DEBUG : sub/yam: Need to transfer - No matching file found at Destination 2025/03/06 01:49:05 DEBUG : potato: Need to transfer - No matching file found at Destination 2025/03/06 01:49:05 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yowelix7taho': Waiting for renames to finish 2025/03/06 01:49:05 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yowelix7taho': Waiting for transfers to finish 2025/03/06 01:49:07 DEBUG : sub/yam: md5 = 183de09aff936e55549bcd7afc6fc678 OK 2025/03/06 01:49:07 INFO : sub/yam: Copied (new) 2025/03/06 01:49:08 DEBUG : potato: md5 = 4670bdf2ddcc90a857100531962f4f50 OK 2025/03/06 01:49:08 INFO : potato: Copied (new) 2025/03/06 01:49:08 DEBUG : Waiting for deletions to finish 2025/03/06 01:49:08 INFO : sub: Set directory modification time (using DirSetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-yowelix7taho'", Local "Local file system at /tmp/rclone3247573043", Modify Window "1ms" 2025/03/06 01:49:09 DEBUG : potato: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/03/06 01:49:09 DEBUG : potato: Unchanged skipping 2025/03/06 01:49:09 INFO : sub: Set directory modification time (using SetModTime) 2025/03/06 01:49:09 DEBUG : Added delayed dir = "sub", newDst=sub 2025/03/06 01:49:10 INFO : Encrypted drive 'TestCryptDrive:rclone-test-yowelix7taho': Making map for --track-renames 2025/03/06 01:49:10 INFO : Encrypted drive 'TestCryptDrive:rclone-test-yowelix7taho': Finished making map for --track-renames 2025/03/06 01:49:10 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yowelix7taho': Waiting for checks to finish 2025/03/06 01:49:10 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yowelix7taho': Waiting for renames to finish 2025/03/06 01:49:11 INFO : sub/yam: Moved (server-side) to: yam 2025/03/06 01:49:11 INFO : yam: Renamed from "sub/yam" 2025/03/06 01:49:11 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yowelix7taho': Waiting for transfers to finish 2025/03/06 01:49:11 DEBUG : Waiting for deletions to finish 2025/03/06 01:49:11 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-yowelix7taho'", Local "Local file system at /tmp/rclone3247573043", Modify Window "1ms" --- PASS: TestSyncWithTrackRenamesStrategyLeaf (9.62s) === RUN TestServerSideMoveLocal run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-yowelix7taho'", Local "Local file system at /tmp/rclone3247573043", Modify Window "1ms" 2025/03/06 01:49:15 DEBUG : Creating backend with remote "/tmp/rclone3247573043/dir1" 2025/03/06 01:49:15 DEBUG : Config file has changed externally - reloading 2025/03/06 01:49:15 DEBUG : Creating backend with remote "/tmp/rclone3247573043/dir2" 2025/03/06 01:49:15 DEBUG : Local file system at /tmp/rclone3247573043/dir2: Using server-side directory move 2025/03/06 01:49:15 INFO : Local file system at /tmp/rclone3247573043/dir2: Server side directory move failed - fallback to file moves: can't copy directory - destination already exists 2025/03/06 01:49:15 DEBUG : file1.txt: Need to transfer - File not found at Destination 2025/03/06 01:49:15 INFO : file1.txt: Moved (server-side) 2025/03/06 01:49:15 DEBUG : Local file system at /tmp/rclone3247573043/dir2: Waiting for checks to finish 2025/03/06 01:49:15 DEBUG : Local file system at /tmp/rclone3247573043/dir2: Waiting for transfers to finish --- PASS: TestServerSideMoveLocal (0.45s) === RUN TestMoveWithDeleteEmptySrcDirs run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-yowelix7taho'", Local "Local file system at /tmp/rclone3247573043", Modify Window "1ms" 2025/03/06 01:49:15 DEBUG : Added delayed dir = "nested", newDst= 2025/03/06 01:49:15 DEBUG : Added delayed dir = "sub dir", newDst= 2025/03/06 01:49:15 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2025/03/06 01:49:15 DEBUG : Added delayed dir = "nested/sub dir", newDst= 2025/03/06 01:49:15 DEBUG : nested/sub dir/file: Need to transfer - File not found at Destination 2025/03/06 01:49:15 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yowelix7taho': Waiting for checks to finish 2025/03/06 01:49:15 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yowelix7taho': Waiting for transfers to finish 2025/03/06 01:49:18 DEBUG : sub dir/hello world: md5 = 208510502b4aec527ff67c3ad40a47a6 OK 2025/03/06 01:49:18 INFO : sub dir/hello world: Copied (new) 2025/03/06 01:49:18 INFO : sub dir/hello world: Deleted 2025/03/06 01:49:19 DEBUG : nested/sub dir/file: md5 = bda01df1235d2709223d2610f83df49c OK 2025/03/06 01:49:19 INFO : nested/sub dir/file: Copied (new) 2025/03/06 01:49:19 INFO : nested/sub dir/file: Deleted 2025/03/06 01:49:20 INFO : nested/sub dir: Set directory modification time (using DirSetModTime) 2025/03/06 01:49:20 INFO : sub dir: Set directory modification time (using DirSetModTime) 2025/03/06 01:49:20 INFO : nested: Set directory modification time (using DirSetModTime) 2025/03/06 01:49:20 INFO : sub dir: Removing directory 2025/03/06 01:49:20 INFO : nested/sub dir: Removing directory 2025/03/06 01:49:20 INFO : nested: Removing directory 2025/03/06 01:49:20 DEBUG : Local file system at /tmp/rclone3247573043: deleted 3 directories run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-yowelix7taho'", Local "Local file system at /tmp/rclone3247573043", Modify Window "1ms" 2025/03/06 01:49:23 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" 2025/03/06 01:49:23 DEBUG : 37qp6d1gohacv723ij3brofbu8/14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "ftp4kuv8se7tqduu6pmmcvjsmk" 2025/03/06 01:49:24 DEBUG : 37qp6d1gohacv723ij3brofbu8: Rmdir: contains trashed file: "14begaa36ih249fgrnfk6nulg0" --- PASS: TestMoveWithDeleteEmptySrcDirs (10.01s) === RUN TestMoveWithoutDeleteEmptySrcDirs run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-yowelix7taho'", Local "Local file system at /tmp/rclone3247573043", Modify Window "1ms" 2025/03/06 01:49:25 DEBUG : Added delayed dir = "nested", newDst= 2025/03/06 01:49:25 DEBUG : Added delayed dir = "sub dir", newDst= 2025/03/06 01:49:25 DEBUG : Added delayed dir = "nested/sub dir", newDst= 2025/03/06 01:49:25 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2025/03/06 01:49:25 DEBUG : nested/sub dir/file: Need to transfer - File not found at Destination 2025/03/06 01:49:25 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yowelix7taho': Waiting for checks to finish 2025/03/06 01:49:25 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yowelix7taho': Waiting for transfers to finish 2025/03/06 01:49:28 DEBUG : sub dir/hello world: md5 = fb23be18f958f642b3cd0157ed8f1469 OK 2025/03/06 01:49:28 INFO : sub dir/hello world: Copied (new) 2025/03/06 01:49:28 INFO : sub dir/hello world: Deleted 2025/03/06 01:49:29 DEBUG : nested/sub dir/file: md5 = 451f1cc8fae13d990eaef6405d1e7151 OK 2025/03/06 01:49:29 INFO : nested/sub dir/file: Copied (new) 2025/03/06 01:49:29 INFO : nested/sub dir/file: Deleted 2025/03/06 01:49:30 INFO : nested/sub dir: Set directory modification time (using DirSetModTime) 2025/03/06 01:49:30 INFO : nested: Set directory modification time (using DirSetModTime) 2025/03/06 01:49:30 INFO : sub dir: Set directory modification time (using DirSetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-yowelix7taho'", Local "Local file system at /tmp/rclone3247573043", Modify Window "1ms" 2025/03/06 01:49:33 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" 2025/03/06 01:49:34 DEBUG : 37qp6d1gohacv723ij3brofbu8/14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "ftp4kuv8se7tqduu6pmmcvjsmk" 2025/03/06 01:49:34 DEBUG : 37qp6d1gohacv723ij3brofbu8: Rmdir: contains trashed file: "14begaa36ih249fgrnfk6nulg0" --- PASS: TestMoveWithoutDeleteEmptySrcDirs (10.30s) === RUN TestMoveWithIgnoreExisting run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-yowelix7taho'", Local "Local file system at /tmp/rclone3247573043", Modify Window "1ms" 2025/03/06 01:49:36 DEBUG : existing: Need to transfer - File not found at Destination 2025/03/06 01:49:36 DEBUG : existing-b: Need to transfer - File not found at Destination 2025/03/06 01:49:36 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yowelix7taho': Waiting for checks to finish 2025/03/06 01:49:36 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yowelix7taho': Waiting for transfers to finish 2025/03/06 01:49:37 DEBUG : existing-b: md5 = 27418d027067b3a4203e9e44a5feab4a OK 2025/03/06 01:49:37 INFO : existing-b: Copied (new) 2025/03/06 01:49:37 INFO : existing-b: Deleted 2025/03/06 01:49:37 DEBUG : existing: md5 = 315c3de6440e280af43dd6c2eaa673af OK 2025/03/06 01:49:37 INFO : existing: Copied (new) 2025/03/06 01:49:37 INFO : existing: Deleted 2025/03/06 01:49:37 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yowelix7taho': Waiting for checks to finish 2025/03/06 01:49:37 DEBUG : existing: Destination exists, skipping 2025/03/06 01:49:37 DEBUG : existing: Not removing source file as destination file exists and --ignore-existing is set 2025/03/06 01:49:37 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yowelix7taho': Waiting for transfers to finish 2025/03/06 01:49:37 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-yowelix7taho'", Local "Local file system at /tmp/rclone3247573043", Modify Window "1ms" --- PASS: TestMoveWithIgnoreExisting (4.22s) === RUN TestServerSideMove run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-yowelix7taho'", Local "Local file system at /tmp/rclone3247573043", Modify Window "1ms" 2025/03/06 01:49:40 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-yuwigat1jihu" 2025/03/06 01:49:40 DEBUG : Creating backend with remote "TestDrive:crypt/3259gccv45l997d1itmki64npafcbt55m1cc6mmusku78sneajpg" 2025/03/06 01:49:42 DEBUG : potato2: md5 = 01ada47edd548ecb1c7573214185cc9f OK 2025/03/06 01:49:43 DEBUG : empty space: md5 = 1e2b93e980def668c660ec996dde425d OK 2025/03/06 01:49:45 DEBUG : potato3: md5 = 2775908f6aa309104cd3f96ff54f8c00 OK sync_test.go:1705: Server side move (if possible) Encrypted drive 'TestCryptDrive:rclone-test-yowelix7taho' -> Encrypted drive 'TestCryptDrive:rclone-test-yuwigat1jihu' 2025/03/06 01:49:47 DEBUG : empty space: md5 = 98afc880add453d23306874555fddd1f OK 2025/03/06 01:49:48 DEBUG : potato3: md5 = 215f0e051fd32047dcab253edd11e9c3 OK 2025/03/06 01:49:49 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yuwigat1jihu': Using server-side directory move 2025/03/06 01:49:49 INFO : Encrypted drive 'TestCryptDrive:rclone-test-yuwigat1jihu': Server side directory move failed - fallback to file moves: can't copy directory - destination already exists 2025/03/06 01:49:49 DEBUG : potato2: Need to transfer - File not found at Destination 2025/03/06 01:49:49 DEBUG : empty space: Size and modification time the same (differ by 0s, within tolerance 1ms) 2025/03/06 01:49:49 DEBUG : empty space: Unchanged skipping 2025/03/06 01:49:49 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yuwigat1jihu': Waiting for checks to finish 2025/03/06 01:49:49 DEBUG : potato3: Sizes differ (src 68 vs dst 60) 2025/03/06 01:49:49 INFO : empty space: Deleted 2025/03/06 01:49:49 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yuwigat1jihu': Waiting for transfers to finish 2025/03/06 01:49:49 INFO : potato3: Deleted 2025/03/06 01:49:49 INFO : potato2: Moved (server-side) 2025/03/06 01:49:50 INFO : potato3: Moved (server-side) 2025/03/06 01:49:50 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-yucedos2biru" 2025/03/06 01:49:50 DEBUG : Creating backend with remote "TestDrive:crypt/kmktgempcs821dgbe3jbmotljg6mq404n7ajj5cmejaqtbs0lf1g" 2025/03/06 01:49:51 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yucedos2biru': Using server-side directory move 2025/03/06 01:49:52 INFO : Encrypted drive 'TestCryptDrive:rclone-test-yucedos2biru': Server side directory move succeeded 2025/03/06 01:49:53 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yucedos2biru': Purge remote 2025/03/06 01:49:54 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yuwigat1jihu': Purge remote 2025/03/06 01:49:54 NOTICE: purge failed: directory not found --- PASS: TestServerSideMove (14.67s) === RUN TestServerSideMoveWithFilter run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-yowelix7taho'", Local "Local file system at /tmp/rclone3247573043", Modify Window "1ms" 2025/03/06 01:49:54 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-jotucug1dodu" 2025/03/06 01:49:54 DEBUG : Config file has changed externally - reloading 2025/03/06 01:49:54 DEBUG : Creating backend with remote "TestDrive:crypt/24arn2f4pgpnd2gckbgft26s902uis267qrsephqqhod8mcbngc0" 2025/03/06 01:49:57 DEBUG : potato2: md5 = 09741a8f02ed5ff397631589d3cb0260 OK 2025/03/06 01:49:58 DEBUG : empty space: md5 = 9cdcf52e8c5bf3751e72182b118fd715 OK 2025/03/06 01:49:59 DEBUG : potato3: md5 = 26075d96eaa174096c3011082082e34b OK sync_test.go:1705: Server side move (if possible) Encrypted drive 'TestCryptDrive:rclone-test-yowelix7taho' -> Encrypted drive 'TestCryptDrive:rclone-test-jotucug1dodu' 2025/03/06 01:50:02 DEBUG : empty space: md5 = 4706712d5c260db74ef74a5f7b458e82 OK 2025/03/06 01:50:03 DEBUG : potato3: md5 = bafe079ad316814b965926c7503737f3 OK 2025/03/06 01:50:04 DEBUG : empty space: Excluded (Size Filter) 2025/03/06 01:50:04 DEBUG : empty space: Excluded 2025/03/06 01:50:04 DEBUG : empty space: Excluded (Size Filter) 2025/03/06 01:50:04 DEBUG : empty space: Excluded 2025/03/06 01:50:04 DEBUG : potato2: Need to transfer - File not found at Destination 2025/03/06 01:50:04 DEBUG : potato3: Sizes differ (src 68 vs dst 60) 2025/03/06 01:50:04 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-jotucug1dodu': Waiting for checks to finish 2025/03/06 01:50:04 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-jotucug1dodu': Waiting for transfers to finish 2025/03/06 01:50:04 INFO : potato3: Deleted 2025/03/06 01:50:04 INFO : potato2: Moved (server-side) 2025/03/06 01:50:05 INFO : potato3: Moved (server-side) 2025/03/06 01:50:05 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-jejagag3line" 2025/03/06 01:50:05 DEBUG : Creating backend with remote "TestDrive:crypt/vtr2vibo1ukn6c34hlf0v0mgsppibso9s4hqrdll640ni42ibne0" 2025/03/06 01:50:06 DEBUG : empty space: Excluded (Size Filter) 2025/03/06 01:50:06 DEBUG : empty space: Excluded 2025/03/06 01:50:06 DEBUG : potato2: Need to transfer - File not found at Destination 2025/03/06 01:50:06 DEBUG : potato3: Need to transfer - File not found at Destination 2025/03/06 01:50:06 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-jejagag3line': Waiting for checks to finish 2025/03/06 01:50:06 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-jejagag3line': Waiting for transfers to finish 2025/03/06 01:50:08 INFO : potato3: Moved (server-side) 2025/03/06 01:50:08 INFO : potato2: Moved (server-side) 2025/03/06 01:50:08 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-jejagag3line': Purge remote 2025/03/06 01:50:09 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-jotucug1dodu': Purge remote --- PASS: TestServerSideMoveWithFilter (16.00s) === RUN TestServerSideMoveDeleteEmptySourceDirs run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-yowelix7taho'", Local "Local file system at /tmp/rclone3247573043", Modify Window "1ms" 2025/03/06 01:50:10 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-botameg4kera" 2025/03/06 01:50:10 DEBUG : Creating backend with remote "TestDrive:crypt/jhlnpboum348i5ev2d99k39othe97s6b2ddbcj8hdn9hg73bp8rg" 2025/03/06 01:50:13 DEBUG : potato2: md5 = 641a0c9565d5b6871a576af4e2556ce3 OK 2025/03/06 01:50:14 DEBUG : empty space: md5 = 4b73a57a1c4a5e43916baaa99792ca44 OK 2025/03/06 01:50:15 DEBUG : potato3: md5 = ecae7d41cb6f05d9e2ddecbde570c3d2 OK 2025/03/06 01:50:15 INFO : tomatoDir: Making directory sync_test.go:1705: Server side move (if possible) Encrypted drive 'TestCryptDrive:rclone-test-yowelix7taho' -> Encrypted drive 'TestCryptDrive:rclone-test-botameg4kera' 2025/03/06 01:50:19 DEBUG : empty space: md5 = f1e7d4b16449e807e0e43f6cacfae2e2 OK 2025/03/06 01:50:20 DEBUG : potato3: md5 = ccb9add0b19f069cf63f6b76f45cdcf5 OK 2025/03/06 01:50:20 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-botameg4kera': Using server-side directory move 2025/03/06 01:50:20 INFO : Encrypted drive 'TestCryptDrive:rclone-test-botameg4kera': Server side directory move failed - fallback to file moves: can't copy directory - destination already exists 2025/03/06 01:50:20 DEBUG : potato2: Need to transfer - File not found at Destination 2025/03/06 01:50:20 DEBUG : Added delayed dir = "tomatoDir", newDst= 2025/03/06 01:50:20 DEBUG : empty space: Size and modification time the same (differ by 0s, within tolerance 1ms) 2025/03/06 01:50:20 DEBUG : empty space: Unchanged skipping 2025/03/06 01:50:20 DEBUG : potato3: Sizes differ (src 68 vs dst 60) 2025/03/06 01:50:21 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-botameg4kera': Waiting for checks to finish 2025/03/06 01:50:21 INFO : potato3: Deleted 2025/03/06 01:50:21 INFO : empty space: Deleted 2025/03/06 01:50:21 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-botameg4kera': Waiting for transfers to finish 2025/03/06 01:50:21 INFO : potato2: Moved (server-side) 2025/03/06 01:50:22 INFO : potato3: Moved (server-side) 2025/03/06 01:50:22 INFO : tomatoDir: Removing directory 2025/03/06 01:50:22 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yowelix7taho': deleted 1 directories 2025/03/06 01:50:23 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-qasocoh7bepe" 2025/03/06 01:50:23 DEBUG : Creating backend with remote "TestDrive:crypt/so0i17uvu9arkpsbi0fb0j2bis5bk3cruap0tgbpcd6qdn47k0a0" 2025/03/06 01:50:24 INFO : tomatoDir: Making directory 2025/03/06 01:50:25 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-qasocoh7bepe': Using server-side directory move 2025/03/06 01:50:25 INFO : Encrypted drive 'TestCryptDrive:rclone-test-qasocoh7bepe': Server side directory move succeeded 2025/03/06 01:50:27 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-qasocoh7bepe': Purge remote 2025/03/06 01:50:27 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-botameg4kera': Purge remote 2025/03/06 01:50:27 NOTICE: purge failed: directory not found --- PASS: TestServerSideMoveDeleteEmptySourceDirs (17.54s) === RUN TestServerSideMoveOverlap run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-yowelix7taho'", Local "Local file system at /tmp/rclone3247573043", Modify Window "1ms" sync_test.go:1910: Skipping test as remote supports DirMove --- SKIP: TestServerSideMoveOverlap (0.42s) === RUN TestSyncOverlap run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-yowelix7taho'", Local "Local file system at /tmp/rclone3247573043", Modify Window "1ms" 2025/03/06 01:50:28 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-yowelix7taho/rclone-sync-test" 2025/03/06 01:50:28 DEBUG : Creating backend with remote "TestDrive:crypt/bi3hem14btfb1nqq3d26d65889gu06un3tb12s4cc9d4a0j3cgu0/i7355aa0sb89uagn75vfjqr6s3e3e1h2et8in57abn1fe8qfego0" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-yowelix7taho'", Local "Local file system at /tmp/rclone3247573043", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-yowelix7taho'", Local "Local file system at /tmp/rclone3247573043", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-yowelix7taho'", Local "Local file system at /tmp/rclone3247573043", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-yowelix7taho'", Local "Local file system at /tmp/rclone3247573043", Modify Window "1ms" --- PASS: TestSyncOverlap (3.69s) === RUN TestSyncOverlapWithFilter run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-yowelix7taho'", Local "Local file system at /tmp/rclone3247573043", Modify Window "1ms" 2025/03/06 01:50:32 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-yowelix7taho/rclone-sync-test" 2025/03/06 01:50:32 DEBUG : Creating backend with remote "TestDrive:crypt/bi3hem14btfb1nqq3d26d65889gu06un3tb12s4cc9d4a0j3cgu0/i7355aa0sb89uagn75vfjqr6s3e3e1h2et8in57abn1fe8qfego0" 2025/03/06 01:50:34 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-yowelix7taho/rclone-sync-test-include/layer2" 2025/03/06 01:50:34 DEBUG : Creating backend with remote "TestDrive:crypt/bi3hem14btfb1nqq3d26d65889gu06un3tb12s4cc9d4a0j3cgu0/khf2vlblvnbf9ftevqm0htmss73hj1j5a7q328e4ohrgs7e2loe0/n01jpl9202nn9ec1rb75h0f1c4" 2025/03/06 01:50:37 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-yowelix7taho/rclone-sync-test-ignore-file" 2025/03/06 01:50:37 DEBUG : Creating backend with remote "TestDrive:crypt/bi3hem14btfb1nqq3d26d65889gu06un3tb12s4cc9d4a0j3cgu0/kmf11jujl9uha3tjganvgpkn45bu778hb5vb5riug1c26b38k7sg" 2025/03/06 01:50:41 DEBUG : rclone-sync-test-ignore-file/.ignore: md5 = 2da635e4aff1fdf9616438ab4162f89d OK 2025/03/06 01:50:42 DEBUG : rclone-sync-test-ignore-file: Excluded 2025/03/06 01:50:42 DEBUG : rclone-sync-test: Excluded 2025/03/06 01:50:42 DEBUG : Added delayed dir = "rclone-sync-test-include", newDst= 2025/03/06 01:50:43 DEBUG : rclone-sync-test-include/layer2: Excluded 2025/03/06 01:50:43 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yowelix7taho/rclone-sync-test': Waiting for checks to finish 2025/03/06 01:50:43 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yowelix7taho/rclone-sync-test': Waiting for transfers to finish 2025/03/06 01:50:43 DEBUG : Waiting for deletions to finish 2025/03/06 01:50:43 INFO : There was nothing to transfer 2025/03/06 01:50:43 DEBUG : rclone-sync-test-ignore-file: Excluded 2025/03/06 01:50:44 DEBUG : rclone-sync-test: Excluded 2025/03/06 01:50:44 DEBUG : rclone-sync-test-include/layer2: Excluded 2025/03/06 01:50:44 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yowelix7taho': Waiting for checks to finish 2025/03/06 01:50:44 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yowelix7taho': Waiting for transfers to finish 2025/03/06 01:50:44 DEBUG : Waiting for deletions to finish 2025/03/06 01:50:44 INFO : rclone-sync-test-include: Removing directory 2025/03/06 01:50:45 DEBUG : khf2vlblvnbf9ftevqm0htmss73hj1j5a7q328e4ohrgs7e2loe0: Rmdir: contains file: "n01jpl9202nn9ec1rb75h0f1c4" 2025/03/06 01:50:45 DEBUG : rclone-sync-test-include: Failed to Rmdir: directory not empty 2025/03/06 01:50:45 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yowelix7taho': failed to delete 1 directories 2025/03/06 01:50:45 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-yowelix7taho'", Local "Local file system at /tmp/rclone3247573043", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-yowelix7taho'", Local "Local file system at /tmp/rclone3247573043", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-yowelix7taho'", Local "Local file system at /tmp/rclone3247573043", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-yowelix7taho'", Local "Local file system at /tmp/rclone3247573043", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-yowelix7taho'", Local "Local file system at /tmp/rclone3247573043", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-yowelix7taho'", Local "Local file system at /tmp/rclone3247573043", Modify Window "1ms" 2025/03/06 01:50:45 DEBUG : rclone-sync-test-ignore-file: Excluded 2025/03/06 01:50:46 DEBUG : rclone-sync-test: Excluded 2025/03/06 01:50:46 DEBUG : Added delayed dir = "rclone-sync-test-include", newDst= 2025/03/06 01:50:46 DEBUG : rclone-sync-test-include/layer2: Excluded 2025/03/06 01:50:46 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yowelix7taho/rclone-sync-test-include/layer2': Waiting for checks to finish 2025/03/06 01:50:46 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yowelix7taho/rclone-sync-test-include/layer2': Waiting for transfers to finish 2025/03/06 01:50:46 DEBUG : Waiting for deletions to finish 2025/03/06 01:50:46 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-yowelix7taho'", Local "Local file system at /tmp/rclone3247573043", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-yowelix7taho'", Local "Local file system at /tmp/rclone3247573043", Modify Window "1ms" 2025/03/06 01:50:47 DEBUG : rclone-sync-test-ignore-file: Excluded 2025/03/06 01:50:47 DEBUG : rclone-sync-test: Excluded 2025/03/06 01:50:48 DEBUG : rclone-sync-test-include/layer2: Excluded 2025/03/06 01:50:48 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yowelix7taho': Waiting for checks to finish 2025/03/06 01:50:48 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yowelix7taho': Waiting for transfers to finish 2025/03/06 01:50:48 DEBUG : Waiting for deletions to finish 2025/03/06 01:50:48 INFO : rclone-sync-test-include: Removing directory 2025/03/06 01:50:48 DEBUG : khf2vlblvnbf9ftevqm0htmss73hj1j5a7q328e4ohrgs7e2loe0: Rmdir: contains file: "n01jpl9202nn9ec1rb75h0f1c4" 2025/03/06 01:50:48 DEBUG : rclone-sync-test-include: Failed to Rmdir: directory not empty 2025/03/06 01:50:48 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yowelix7taho': failed to delete 1 directories 2025/03/06 01:50:48 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-yowelix7taho'", Local "Local file system at /tmp/rclone3247573043", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-yowelix7taho'", Local "Local file system at /tmp/rclone3247573043", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-yowelix7taho'", Local "Local file system at /tmp/rclone3247573043", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-yowelix7taho'", Local "Local file system at /tmp/rclone3247573043", Modify Window "1ms" 2025/03/06 01:50:49 DEBUG : : Excluded 2025/03/06 01:50:49 DEBUG : rclone-sync-test-ignore-file: Excluded 2025/03/06 01:50:49 DEBUG : rclone-sync-test: Excluded 2025/03/06 01:50:49 DEBUG : Added delayed dir = "rclone-sync-test-include", newDst= 2025/03/06 01:50:50 DEBUG : rclone-sync-test-include/layer2: Excluded 2025/03/06 01:50:50 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yowelix7taho/rclone-sync-test-ignore-file': Waiting for checks to finish 2025/03/06 01:50:50 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yowelix7taho/rclone-sync-test-ignore-file': Waiting for transfers to finish 2025/03/06 01:50:50 DEBUG : Waiting for deletions to finish 2025/03/06 01:50:50 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-yowelix7taho'", Local "Local file system at /tmp/rclone3247573043", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-yowelix7taho'", Local "Local file system at /tmp/rclone3247573043", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-yowelix7taho'", Local "Local file system at /tmp/rclone3247573043", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-yowelix7taho'", Local "Local file system at /tmp/rclone3247573043", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-yowelix7taho'", Local "Local file system at /tmp/rclone3247573043", Modify Window "1ms" 2025/03/06 01:50:52 DEBUG : khf2vlblvnbf9ftevqm0htmss73hj1j5a7q328e4ohrgs7e2loe0: Rmdir: contains trashed file: "n01jpl9202nn9ec1rb75h0f1c4" 2025/03/06 01:50:53 DEBUG : kmf11jujl9uha3tjganvgpkn45bu778hb5vb5riug1c26b38k7sg: Rmdir: contains trashed file: "i0t74httmdlljg425j6tg570d8" --- PASS: TestSyncOverlapWithFilter (29.67s) === RUN TestSyncCompareDest run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-yowelix7taho'", Local "Local file system at /tmp/rclone3247573043", Modify Window "1ms" 2025/03/06 01:51:02 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-yowelix7taho/dst" 2025/03/06 01:51:02 DEBUG : Creating backend with remote "TestDrive:crypt/bi3hem14btfb1nqq3d26d65889gu06un3tb12s4cc9d4a0j3cgu0/31u3jie661vd5p8j7rtc3hgbh0" 2025/03/06 01:51:03 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-yowelix7taho/CompareDest" 2025/03/06 01:51:03 DEBUG : Creating backend with remote "TestDrive:crypt/bi3hem14btfb1nqq3d26d65889gu06un3tb12s4cc9d4a0j3cgu0/gveqi14airsml4bgu7krj116o8" 2025/03/06 01:51:05 DEBUG : one: Need to transfer - File not found at Destination 2025/03/06 01:51:05 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yowelix7taho/dst': Waiting for checks to finish 2025/03/06 01:51:05 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yowelix7taho/dst': Waiting for transfers to finish 2025/03/06 01:51:07 DEBUG : one: md5 = 9276aba8da2273a57292b3401dd22539 OK 2025/03/06 01:51:07 INFO : one: Copied (new) 2025/03/06 01:51:07 DEBUG : Waiting for deletions to finish 2025/03/06 01:51:08 DEBUG : one: Sizes differ (src 5 vs dst 3) 2025/03/06 01:51:08 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yowelix7taho/dst': Waiting for checks to finish 2025/03/06 01:51:09 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yowelix7taho/dst': Waiting for transfers to finish 2025/03/06 01:51:10 DEBUG : one: md5 = bc552d53c2baca4ba2d30d881125cca7 OK 2025/03/06 01:51:10 INFO : one: Copied (replaced existing) 2025/03/06 01:51:10 DEBUG : Waiting for deletions to finish 2025/03/06 01:51:12 DEBUG : dst/one: md5 = 0e88e08a2d76f78761a7d8f2297bf109 OK 2025/03/06 01:51:14 DEBUG : CompareDest/one: md5 = 751799f41a6d33aafedb7fd2f5d07167 OK 2025/03/06 01:51:14 DEBUG : one: Sizes differ (src 5 vs dst 3) 2025/03/06 01:51:14 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yowelix7taho/dst': Waiting for checks to finish 2025/03/06 01:51:15 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/03/06 01:51:15 DEBUG : one: Destination found in --compare-dest, skipping 2025/03/06 01:51:15 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yowelix7taho/dst': Waiting for transfers to finish 2025/03/06 01:51:15 DEBUG : Waiting for deletions to finish 2025/03/06 01:51:15 INFO : There was nothing to transfer 2025/03/06 01:51:17 DEBUG : CompareDest/two: md5 = 46b9ba638117ff029b90934454dedfc2 OK 2025/03/06 01:51:18 DEBUG : two: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/03/06 01:51:18 DEBUG : two: Destination found in --compare-dest, skipping 2025/03/06 01:51:18 DEBUG : one: Sizes differ (src 5 vs dst 3) 2025/03/06 01:51:18 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yowelix7taho/dst': Waiting for checks to finish 2025/03/06 01:51:18 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/03/06 01:51:18 DEBUG : one: Destination found in --compare-dest, skipping 2025/03/06 01:51:18 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yowelix7taho/dst': Waiting for transfers to finish 2025/03/06 01:51:18 DEBUG : Waiting for deletions to finish 2025/03/06 01:51:18 INFO : There was nothing to transfer 2025/03/06 01:51:19 DEBUG : two: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/03/06 01:51:19 DEBUG : two: Destination found in --compare-dest, skipping 2025/03/06 01:51:19 DEBUG : one: Sizes differ (src 5 vs dst 3) 2025/03/06 01:51:19 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yowelix7taho/dst': Waiting for checks to finish 2025/03/06 01:51:19 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/03/06 01:51:19 DEBUG : one: Destination found in --compare-dest, skipping 2025/03/06 01:51:19 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yowelix7taho/dst': Waiting for transfers to finish 2025/03/06 01:51:19 DEBUG : Waiting for deletions to finish 2025/03/06 01:51:19 INFO : There was nothing to transfer sync_test.go:2175: No hash on uploaded file so skipping compare timestamp test 2025/03/06 01:51:21 DEBUG : two: Sizes differ (src 5 vs dst 3) 2025/03/06 01:51:21 DEBUG : two: Need to transfer - File not found at Destination 2025/03/06 01:51:21 DEBUG : one: Sizes differ (src 5 vs dst 3) 2025/03/06 01:51:21 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yowelix7taho/dst': Waiting for checks to finish 2025/03/06 01:51:21 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/03/06 01:51:21 DEBUG : one: Destination found in --compare-dest, skipping 2025/03/06 01:51:21 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yowelix7taho/dst': Waiting for transfers to finish 2025/03/06 01:51:22 DEBUG : two: md5 = 3984dec0c35278968e55578856ab2e6d OK 2025/03/06 01:51:22 INFO : two: Copied (new) 2025/03/06 01:51:22 DEBUG : Waiting for deletions to finish 2025/03/06 01:51:26 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k" 2025/03/06 01:51:26 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" 2025/03/06 01:51:26 DEBUG : gveqi14airsml4bgu7krj116o8: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k" 2025/03/06 01:51:26 DEBUG : gveqi14airsml4bgu7krj116o8: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" --- PASS: TestSyncCompareDest (25.44s) === RUN TestSyncMultipleCompareDest run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-yowelix7taho'", Local "Local file system at /tmp/rclone3247573043", Modify Window "1ms" 2025/03/06 01:51:29 DEBUG : pre-dest1/1: md5 = bbab45ac4c3995a04f768eb4a2de1fea OK 2025/03/06 01:51:32 DEBUG : pre-dest2/2: md5 = 4c5758414cdf4d7b8bcf44b2267d9402 OK 2025/03/06 01:51:33 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-yowelix7taho/dest" 2025/03/06 01:51:33 DEBUG : Creating backend with remote "TestDrive:crypt/bi3hem14btfb1nqq3d26d65889gu06un3tb12s4cc9d4a0j3cgu0/rg03c1jvnehrrc617i0lnqjddc" 2025/03/06 01:51:34 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-yowelix7taho/pre-dest1" 2025/03/06 01:51:34 DEBUG : Creating backend with remote "TestDrive:crypt/bi3hem14btfb1nqq3d26d65889gu06un3tb12s4cc9d4a0j3cgu0/bbnblvh6k061ssopqrp18kd7gc" 2025/03/06 01:51:35 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-yowelix7taho/pre-dest2" 2025/03/06 01:51:35 DEBUG : Creating backend with remote "TestDrive:crypt/bi3hem14btfb1nqq3d26d65889gu06un3tb12s4cc9d4a0j3cgu0/dgicm1h6b5ejvlltm8eeif0bnk" 2025/03/06 01:51:36 DEBUG : 1: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/03/06 01:51:36 DEBUG : 1: Destination found in --compare-dest, skipping 2025/03/06 01:51:37 DEBUG : 2: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/03/06 01:51:37 DEBUG : 2: Destination found in --compare-dest, skipping 2025/03/06 01:51:37 DEBUG : 3: Need to transfer - File not found at Destination 2025/03/06 01:51:37 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yowelix7taho/dest': Waiting for checks to finish 2025/03/06 01:51:37 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yowelix7taho/dest': Waiting for transfers to finish 2025/03/06 01:51:39 DEBUG : 3: md5 = d74272e99fd95ccaf130792a6602ea01 OK 2025/03/06 01:51:39 INFO : 3: Copied (new) 2025/03/06 01:51:39 DEBUG : Waiting for deletions to finish 2025/03/06 01:51:42 DEBUG : dgicm1h6b5ejvlltm8eeif0bnk: Rmdir: contains trashed file: "1ghu8geql9vrl726n32nrf65bc" 2025/03/06 01:51:43 DEBUG : bbnblvh6k061ssopqrp18kd7gc: Rmdir: contains trashed file: "skbfko3oil7es0lj68ob574sro" 2025/03/06 01:51:43 DEBUG : rg03c1jvnehrrc617i0lnqjddc: Rmdir: contains trashed file: "g072p7hmjchlnj0gibe64c1epg" --- PASS: TestSyncMultipleCompareDest (16.85s) === RUN TestSyncCopyDest run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-yowelix7taho'", Local "Local file system at /tmp/rclone3247573043", Modify Window "1ms" 2025/03/06 01:51:44 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-yowelix7taho/dst" 2025/03/06 01:51:44 DEBUG : Creating backend with remote "TestDrive:crypt/bi3hem14btfb1nqq3d26d65889gu06un3tb12s4cc9d4a0j3cgu0/31u3jie661vd5p8j7rtc3hgbh0" 2025/03/06 01:51:45 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-yowelix7taho/CopyDest" 2025/03/06 01:51:45 DEBUG : Creating backend with remote "TestDrive:crypt/bi3hem14btfb1nqq3d26d65889gu06un3tb12s4cc9d4a0j3cgu0/d09o6po3f7bm6ce32vdgs8h9ls" 2025/03/06 01:51:47 DEBUG : one: Need to transfer - File not found at Destination 2025/03/06 01:51:47 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yowelix7taho/dst': Waiting for checks to finish 2025/03/06 01:51:47 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yowelix7taho/dst': Waiting for transfers to finish 2025/03/06 01:51:49 DEBUG : one: md5 = 30d96d33050badbf2f6cec7ee49c9227 OK 2025/03/06 01:51:49 INFO : one: Copied (new) 2025/03/06 01:51:49 DEBUG : Waiting for deletions to finish 2025/03/06 01:51:51 DEBUG : one: Sizes differ (src 5 vs dst 3) 2025/03/06 01:51:51 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yowelix7taho/dst': Waiting for checks to finish 2025/03/06 01:51:51 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yowelix7taho/dst': Waiting for transfers to finish 2025/03/06 01:51:52 DEBUG : one: md5 = 3d0f4980eaea047829d6ceeef84eb8cf OK 2025/03/06 01:51:52 INFO : one: Copied (replaced existing) 2025/03/06 01:51:52 DEBUG : Waiting for deletions to finish 2025/03/06 01:51:54 DEBUG : dst/one: md5 = 901befcd4de8e17ac5a7d679f803883e OK 2025/03/06 01:51:56 DEBUG : CopyDest/one: md5 = 0de5da6ead79f7beb957d1f3270fd035 OK 2025/03/06 01:51:57 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-yowelix7taho/BackupDir" 2025/03/06 01:51:57 DEBUG : Creating backend with remote "TestDrive:crypt/bi3hem14btfb1nqq3d26d65889gu06un3tb12s4cc9d4a0j3cgu0/s6dbk3lfi7c9kfvo6j7bla9m0g" 2025/03/06 01:51:58 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yowelix7taho/dst': Waiting for checks to finish 2025/03/06 01:51:58 DEBUG : one: Sizes differ (src 5 vs dst 3) 2025/03/06 01:51:59 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/03/06 01:51:59 DEBUG : one: Sizes differ (src 5 vs dst 3) 2025/03/06 01:52:01 INFO : one: Moved (server-side) 2025/03/06 01:52:02 INFO : one: Copied (server-side copy) 2025/03/06 01:52:02 DEBUG : one: Destination found in --copy-dest, using server-side copy 2025/03/06 01:52:02 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yowelix7taho/dst': Waiting for transfers to finish 2025/03/06 01:52:02 DEBUG : Waiting for deletions to finish 2025/03/06 01:52:04 DEBUG : CopyDest/two: md5 = 9d484c4e346e8505d922b0334c2ea04d OK 2025/03/06 01:52:05 DEBUG : two: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/03/06 01:52:06 INFO : two: Copied (server-side copy) 2025/03/06 01:52:06 DEBUG : two: Destination found in --copy-dest, using server-side copy 2025/03/06 01:52:06 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yowelix7taho/dst': Waiting for checks to finish 2025/03/06 01:52:06 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/03/06 01:52:06 DEBUG : one: Unchanged skipping 2025/03/06 01:52:06 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yowelix7taho/dst': Waiting for transfers to finish 2025/03/06 01:52:06 DEBUG : Waiting for deletions to finish 2025/03/06 01:52:06 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/03/06 01:52:06 DEBUG : one: Unchanged skipping 2025/03/06 01:52:06 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yowelix7taho/dst': Waiting for checks to finish 2025/03/06 01:52:06 DEBUG : two: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/03/06 01:52:06 DEBUG : two: Unchanged skipping 2025/03/06 01:52:06 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yowelix7taho/dst': Waiting for transfers to finish 2025/03/06 01:52:06 DEBUG : Waiting for deletions to finish 2025/03/06 01:52:06 INFO : There was nothing to transfer 2025/03/06 01:52:08 DEBUG : CopyDest/three: md5 = 64a48353674b666178e5dd0883d3ea86 OK 2025/03/06 01:52:09 DEBUG : three: Sizes differ (src 7 vs dst 5) 2025/03/06 01:52:09 DEBUG : three: Destination not found in --copy-dest 2025/03/06 01:52:09 DEBUG : three: Need to transfer - File not found at Destination 2025/03/06 01:52:09 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/03/06 01:52:09 DEBUG : one: Unchanged skipping 2025/03/06 01:52:09 DEBUG : two: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/03/06 01:52:09 DEBUG : two: Unchanged skipping 2025/03/06 01:52:09 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yowelix7taho/dst': Waiting for checks to finish 2025/03/06 01:52:09 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yowelix7taho/dst': Waiting for transfers to finish 2025/03/06 01:52:11 DEBUG : three: md5 = ab39eb0da8b75a6796e16e2ae4691e44 OK 2025/03/06 01:52:11 INFO : three: Copied (new) 2025/03/06 01:52:11 DEBUG : Waiting for deletions to finish 2025/03/06 01:52:15 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "b6jdmn2b1adrhc8vikh7edr9os" 2025/03/06 01:52:15 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" 2025/03/06 01:52:15 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k" 2025/03/06 01:52:16 DEBUG : d09o6po3f7bm6ce32vdgs8h9ls: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" 2025/03/06 01:52:16 DEBUG : d09o6po3f7bm6ce32vdgs8h9ls: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k" 2025/03/06 01:52:16 DEBUG : d09o6po3f7bm6ce32vdgs8h9ls: Rmdir: contains trashed file: "b6jdmn2b1adrhc8vikh7edr9os" 2025/03/06 01:52:16 DEBUG : s6dbk3lfi7c9kfvo6j7bla9m0g: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" --- PASS: TestSyncCopyDest (32.98s) === RUN TestSyncBackupDir run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-yowelix7taho'", Local "Local file system at /tmp/rclone3247573043", Modify Window "1ms" 2025/03/06 01:52:19 DEBUG : dst/one: md5 = aa7cdfa5b35af3112923293490170ed2 OK 2025/03/06 01:52:20 DEBUG : dst/two: md5 = 33ef14c2d1d02dfdafe00f9998bd614d OK 2025/03/06 01:52:22 DEBUG : dst/three.txt: md5 = f25dec49654380cf83b92ea0e85ed5af OK 2025/03/06 01:52:22 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-yowelix7taho/dst" 2025/03/06 01:52:22 DEBUG : Creating backend with remote "TestDrive:crypt/bi3hem14btfb1nqq3d26d65889gu06un3tb12s4cc9d4a0j3cgu0/31u3jie661vd5p8j7rtc3hgbh0" 2025/03/06 01:52:23 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-yowelix7taho/backup" 2025/03/06 01:52:23 DEBUG : Creating backend with remote "TestDrive:crypt/bi3hem14btfb1nqq3d26d65889gu06un3tb12s4cc9d4a0j3cgu0/1nrff024r7pq65ecp72fc28jb0" 2025/03/06 01:52:25 DEBUG : one: Sizes differ (src 4 vs dst 3) 2025/03/06 01:52:25 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yowelix7taho/dst': Waiting for checks to finish 2025/03/06 01:52:25 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/03/06 01:52:25 DEBUG : two: Unchanged skipping 2025/03/06 01:52:26 INFO : one: Moved (server-side) 2025/03/06 01:52:26 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yowelix7taho/dst': Waiting for transfers to finish 2025/03/06 01:52:28 DEBUG : one: md5 = 7cad2938545cb489a3ac1be5690aa8a2 OK 2025/03/06 01:52:28 INFO : one: Copied (new) 2025/03/06 01:52:28 DEBUG : Waiting for deletions to finish 2025/03/06 01:52:29 INFO : three.txt: Moved (server-side) 2025/03/06 01:52:29 INFO : three.txt: Moved into backup dir 2025/03/06 01:52:30 DEBUG : dst/three.txt: md5 = e09b74783f66fe8fc159e342bd8272d2 OK 2025/03/06 01:52:31 DEBUG : one: Sizes differ (src 5 vs dst 4) 2025/03/06 01:52:31 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/03/06 01:52:31 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yowelix7taho/dst': Waiting for checks to finish 2025/03/06 01:52:31 DEBUG : two: Unchanged skipping 2025/03/06 01:52:32 INFO : one: Deleted 2025/03/06 01:52:32 INFO : one: Moved (server-side) 2025/03/06 01:52:32 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yowelix7taho/dst': Waiting for transfers to finish 2025/03/06 01:52:34 DEBUG : one: md5 = 966e22a591e6eccc5ebf648e6e8dadf6 OK 2025/03/06 01:52:34 INFO : one: Copied (new) 2025/03/06 01:52:34 DEBUG : Waiting for deletions to finish 2025/03/06 01:52:34 INFO : three.txt: Deleted 2025/03/06 01:52:35 INFO : three.txt: Moved (server-side) 2025/03/06 01:52:35 INFO : three.txt: Moved into backup dir 2025/03/06 01:52:38 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" 2025/03/06 01:52:38 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k" 2025/03/06 01:52:39 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "tr2hj63d80ftlmvm6a952snjcc" 2025/03/06 01:52:39 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" 2025/03/06 01:52:39 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" 2025/03/06 01:52:39 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "tr2hj63d80ftlmvm6a952snjcc" --- PASS: TestSyncBackupDir (22.48s) === RUN TestSyncBackupDirWithSuffix run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-yowelix7taho'", Local "Local file system at /tmp/rclone3247573043", Modify Window "1ms" 2025/03/06 01:52:41 DEBUG : dst/one: md5 = 4c257560190916b4cdf589b627e4c78e OK 2025/03/06 01:52:43 DEBUG : dst/two: md5 = d100924662c68aa9ceb82d9983922270 OK 2025/03/06 01:52:44 DEBUG : dst/three.txt: md5 = 40f73fbcd1ddcf884af0cda1f0d8aa23 OK 2025/03/06 01:52:45 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-yowelix7taho/dst" 2025/03/06 01:52:45 DEBUG : Creating backend with remote "TestDrive:crypt/bi3hem14btfb1nqq3d26d65889gu06un3tb12s4cc9d4a0j3cgu0/31u3jie661vd5p8j7rtc3hgbh0" 2025/03/06 01:52:46 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-yowelix7taho/backup" 2025/03/06 01:52:46 DEBUG : Creating backend with remote "TestDrive:crypt/bi3hem14btfb1nqq3d26d65889gu06un3tb12s4cc9d4a0j3cgu0/1nrff024r7pq65ecp72fc28jb0" 2025/03/06 01:52:47 DEBUG : one: Sizes differ (src 4 vs dst 3) 2025/03/06 01:52:47 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/03/06 01:52:47 DEBUG : two: Unchanged skipping 2025/03/06 01:52:47 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yowelix7taho/dst': Waiting for checks to finish 2025/03/06 01:52:49 INFO : one: Moved (server-side) to: one.bak 2025/03/06 01:52:49 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yowelix7taho/dst': Waiting for transfers to finish 2025/03/06 01:52:50 DEBUG : one: md5 = 19d106fd0d09b1a9d9c18e301dccdd15 OK 2025/03/06 01:52:50 INFO : one: Copied (new) 2025/03/06 01:52:50 DEBUG : Waiting for deletions to finish 2025/03/06 01:52:51 INFO : three.txt: Moved (server-side) to: three.txt.bak 2025/03/06 01:52:51 INFO : three.txt: Moved into backup dir 2025/03/06 01:52:53 DEBUG : dst/three.txt: md5 = ca0ec95573a0c614d846525fd4470097 OK 2025/03/06 01:52:54 DEBUG : one: Sizes differ (src 5 vs dst 4) 2025/03/06 01:52:54 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yowelix7taho/dst': Waiting for checks to finish 2025/03/06 01:52:54 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/03/06 01:52:54 DEBUG : two: Unchanged skipping 2025/03/06 01:52:54 INFO : one.bak: Deleted 2025/03/06 01:52:55 INFO : one: Moved (server-side) to: one.bak 2025/03/06 01:52:55 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yowelix7taho/dst': Waiting for transfers to finish 2025/03/06 01:52:56 DEBUG : one: md5 = 0da576e1cc90763a4bdff50f385ac39d OK 2025/03/06 01:52:56 INFO : one: Copied (new) 2025/03/06 01:52:56 DEBUG : Waiting for deletions to finish 2025/03/06 01:52:57 INFO : three.txt.bak: Deleted 2025/03/06 01:52:57 INFO : three.txt: Moved (server-side) to: three.txt.bak 2025/03/06 01:52:57 INFO : three.txt: Moved into backup dir 2025/03/06 01:53:00 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" 2025/03/06 01:53:00 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k" 2025/03/06 01:53:01 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "sk91qgsqfn0r271r2ehsaoc20c" 2025/03/06 01:53:01 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "qltcak2uaegtmcoa8vijdppbp8" 2025/03/06 01:53:01 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "sk91qgsqfn0r271r2ehsaoc20c" 2025/03/06 01:53:01 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "qltcak2uaegtmcoa8vijdppbp8" --- PASS: TestSyncBackupDirWithSuffix (22.41s) === RUN TestSyncBackupDirWithSuffixKeepExtension run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-yowelix7taho'", Local "Local file system at /tmp/rclone3247573043", Modify Window "1ms" 2025/03/06 01:53:04 DEBUG : dst/one: md5 = 5d50f663b70c7b6d0f861edb8b943bd0 OK 2025/03/06 01:53:05 DEBUG : dst/two: md5 = aabf3370c2e08ea67b0b0b775626e30a OK 2025/03/06 01:53:06 DEBUG : dst/three.txt: md5 = d2552db35e5d1141a24db700fa5ced06 OK 2025/03/06 01:53:07 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-yowelix7taho/dst" 2025/03/06 01:53:07 DEBUG : Creating backend with remote "TestDrive:crypt/bi3hem14btfb1nqq3d26d65889gu06un3tb12s4cc9d4a0j3cgu0/31u3jie661vd5p8j7rtc3hgbh0" 2025/03/06 01:53:08 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-yowelix7taho/backup" 2025/03/06 01:53:08 DEBUG : Creating backend with remote "TestDrive:crypt/bi3hem14btfb1nqq3d26d65889gu06un3tb12s4cc9d4a0j3cgu0/1nrff024r7pq65ecp72fc28jb0" 2025/03/06 01:53:09 DEBUG : one: Sizes differ (src 4 vs dst 3) 2025/03/06 01:53:09 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/03/06 01:53:09 DEBUG : two: Unchanged skipping 2025/03/06 01:53:09 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yowelix7taho/dst': Waiting for checks to finish 2025/03/06 01:53:11 INFO : one: Moved (server-side) to: one-2019-01-01 2025/03/06 01:53:11 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yowelix7taho/dst': Waiting for transfers to finish 2025/03/06 01:53:12 DEBUG : one: md5 = fc61ef09a2dbd84ef7df9fb074e1d7fc OK 2025/03/06 01:53:12 INFO : one: Copied (new) 2025/03/06 01:53:12 DEBUG : Waiting for deletions to finish 2025/03/06 01:53:13 INFO : three.txt: Moved (server-side) to: three-2019-01-01.txt 2025/03/06 01:53:13 INFO : three.txt: Moved into backup dir 2025/03/06 01:53:15 DEBUG : dst/three.txt: md5 = 5f71861d01f2f5613a521d1c80a2f142 OK 2025/03/06 01:53:16 DEBUG : one: Sizes differ (src 5 vs dst 4) 2025/03/06 01:53:16 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/03/06 01:53:16 DEBUG : two: Unchanged skipping 2025/03/06 01:53:16 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yowelix7taho/dst': Waiting for checks to finish 2025/03/06 01:53:16 INFO : one-2019-01-01: Deleted 2025/03/06 01:53:17 INFO : one: Moved (server-side) to: one-2019-01-01 2025/03/06 01:53:17 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yowelix7taho/dst': Waiting for transfers to finish 2025/03/06 01:53:18 DEBUG : one: md5 = 540ee81304d44cf8efcbb5d2f967c90b OK 2025/03/06 01:53:18 INFO : one: Copied (new) 2025/03/06 01:53:18 DEBUG : Waiting for deletions to finish 2025/03/06 01:53:19 INFO : three-2019-01-01.txt: Deleted 2025/03/06 01:53:20 INFO : three.txt: Moved (server-side) to: three-2019-01-01.txt 2025/03/06 01:53:20 INFO : three.txt: Moved into backup dir 2025/03/06 01:53:23 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" 2025/03/06 01:53:23 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k" 2025/03/06 01:53:23 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "qtq2f6qq4lgpsmj88vb7147qje3prudmtfdtr2342fth58vo9a50" 2025/03/06 01:53:23 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "jcjl1bv3ep0v8kt35lqql1co90" 2025/03/06 01:53:23 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "jcjl1bv3ep0v8kt35lqql1co90" 2025/03/06 01:53:23 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "qtq2f6qq4lgpsmj88vb7147qje3prudmtfdtr2342fth58vo9a50" --- PASS: TestSyncBackupDirWithSuffixKeepExtension (22.31s) === RUN TestSyncBackupDirSuffixOnly run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-yowelix7taho'", Local "Local file system at /tmp/rclone3247573043", Modify Window "1ms" 2025/03/06 01:53:26 DEBUG : dst/one: md5 = 4c3ef68f25d18ffdf06f9f07fb48cf25 OK 2025/03/06 01:53:28 DEBUG : dst/two: md5 = 4e2eee36882ad8ea344290b8e32258f4 OK 2025/03/06 01:53:30 DEBUG : dst/three.txt: md5 = f067d1166ae2d99a6647f95ee4b7bed2 OK 2025/03/06 01:53:30 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-yowelix7taho/dst" 2025/03/06 01:53:30 DEBUG : Creating backend with remote "TestDrive:crypt/bi3hem14btfb1nqq3d26d65889gu06un3tb12s4cc9d4a0j3cgu0/31u3jie661vd5p8j7rtc3hgbh0" 2025/03/06 01:53:31 DEBUG : one: Sizes differ (src 4 vs dst 3) 2025/03/06 01:53:31 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/03/06 01:53:31 DEBUG : two: Unchanged skipping 2025/03/06 01:53:31 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yowelix7taho/dst': Waiting for checks to finish 2025/03/06 01:53:32 INFO : one: Moved (server-side) to: one.bak 2025/03/06 01:53:32 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yowelix7taho/dst': Waiting for transfers to finish 2025/03/06 01:53:33 DEBUG : one: md5 = 5d1b0bd5bf15494e25f203fd2df1a990 OK 2025/03/06 01:53:33 INFO : one: Copied (new) 2025/03/06 01:53:33 DEBUG : Waiting for deletions to finish 2025/03/06 01:53:34 INFO : three.txt: Moved (server-side) to: three.txt.bak 2025/03/06 01:53:34 INFO : three.txt: Moved into backup dir 2025/03/06 01:53:36 DEBUG : dst/three.txt: md5 = 3c693faba400c617afdf5785149039d8 OK 2025/03/06 01:53:37 DEBUG : three.txt.bak: Excluded (Path Filter) 2025/03/06 01:53:37 DEBUG : three.txt.bak: Excluded 2025/03/06 01:53:37 DEBUG : one.bak: Excluded (Path Filter) 2025/03/06 01:53:37 DEBUG : one.bak: Excluded 2025/03/06 01:53:37 DEBUG : one: Sizes differ (src 5 vs dst 4) 2025/03/06 01:53:37 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yowelix7taho/dst': Waiting for checks to finish 2025/03/06 01:53:37 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/03/06 01:53:37 DEBUG : two: Unchanged skipping 2025/03/06 01:53:38 INFO : one.bak: Deleted 2025/03/06 01:53:38 INFO : one: Moved (server-side) to: one.bak 2025/03/06 01:53:38 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yowelix7taho/dst': Waiting for transfers to finish 2025/03/06 01:53:40 DEBUG : one: md5 = d62b99790157f9d7e4cc921d6a456f07 OK 2025/03/06 01:53:40 INFO : one: Copied (new) 2025/03/06 01:53:40 DEBUG : Waiting for deletions to finish 2025/03/06 01:53:40 INFO : three.txt.bak: Deleted 2025/03/06 01:53:41 INFO : three.txt: Moved (server-side) to: three.txt.bak 2025/03/06 01:53:41 INFO : three.txt: Moved into backup dir 2025/03/06 01:53:44 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" 2025/03/06 01:53:44 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "sk91qgsqfn0r271r2ehsaoc20c" 2025/03/06 01:53:44 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "qltcak2uaegtmcoa8vijdppbp8" 2025/03/06 01:53:44 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "sk91qgsqfn0r271r2ehsaoc20c" 2025/03/06 01:53:44 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "qltcak2uaegtmcoa8vijdppbp8" 2025/03/06 01:53:44 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k" --- PASS: TestSyncBackupDirSuffixOnly (20.54s) === RUN TestSyncSuffix run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-yowelix7taho'", Local "Local file system at /tmp/rclone3247573043", Modify Window "1ms" 2025/03/06 01:53:47 DEBUG : dst/one: md5 = 13120ac33f4c7df3c6d45c1bddaa893f OK 2025/03/06 01:53:48 DEBUG : dst/two: md5 = 108cfd0e8b48b24c9688a16bf33e5447 OK 2025/03/06 01:53:49 DEBUG : dst/three.txt: md5 = a202d306fb9fd4aac02219afb751ec02 OK 2025/03/06 01:53:50 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-yowelix7taho/dst" 2025/03/06 01:53:50 DEBUG : Creating backend with remote "TestDrive:crypt/bi3hem14btfb1nqq3d26d65889gu06un3tb12s4cc9d4a0j3cgu0/31u3jie661vd5p8j7rtc3hgbh0" 2025/03/06 01:53:51 DEBUG : one: Sizes differ (src 4 vs dst 3) 2025/03/06 01:53:52 INFO : one: Moved (server-side) to: one.bak 2025/03/06 01:53:53 DEBUG : one: md5 = 45811e9d73a958e4782b14cb500b1e0d OK 2025/03/06 01:53:53 INFO : one: Copied (new) 2025/03/06 01:53:53 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/03/06 01:53:53 DEBUG : two: Unchanged skipping 2025/03/06 01:53:53 DEBUG : three.txt: Sizes differ (src 6 vs dst 5) 2025/03/06 01:53:54 INFO : three.txt: Moved (server-side) to: three.txt.bak 2025/03/06 01:53:56 DEBUG : three.txt: md5 = 87d1cf8ba01be27fd2143be9ab50995e OK 2025/03/06 01:53:56 INFO : three.txt: Copied (new) 2025/03/06 01:53:57 DEBUG : one: Sizes differ (src 5 vs dst 4) 2025/03/06 01:53:58 INFO : one.bak: Deleted 2025/03/06 01:53:58 INFO : one: Moved (server-side) to: one.bak 2025/03/06 01:54:00 DEBUG : one: md5 = 1f7194e77d67acc4af74d463adf97a3a OK 2025/03/06 01:54:00 INFO : one: Copied (new) 2025/03/06 01:54:00 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/03/06 01:54:00 DEBUG : two: Unchanged skipping 2025/03/06 01:54:00 DEBUG : three.txt: Sizes differ (src 19 vs dst 6) 2025/03/06 01:54:01 INFO : three.txt.bak: Deleted 2025/03/06 01:54:01 INFO : three.txt: Moved (server-side) to: three.txt.bak 2025/03/06 01:54:03 DEBUG : three.txt: md5 = d942f1ab8b9e4c4043788f9c5306dab1 OK 2025/03/06 01:54:03 INFO : three.txt: Copied (new) 2025/03/06 01:54:06 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "tr2hj63d80ftlmvm6a952snjcc" 2025/03/06 01:54:06 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" 2025/03/06 01:54:06 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "qltcak2uaegtmcoa8vijdppbp8" 2025/03/06 01:54:06 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "sk91qgsqfn0r271r2ehsaoc20c" 2025/03/06 01:54:06 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "sk91qgsqfn0r271r2ehsaoc20c" 2025/03/06 01:54:06 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k" 2025/03/06 01:54:06 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "qltcak2uaegtmcoa8vijdppbp8" --- PASS: TestSyncSuffix (22.18s) === RUN TestSyncSuffixKeepExtension run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-yowelix7taho'", Local "Local file system at /tmp/rclone3247573043", Modify Window "1ms" 2025/03/06 01:54:09 DEBUG : dst/one: md5 = 647231a0eb1b35275d52423de1c61593 OK 2025/03/06 01:54:11 DEBUG : dst/two: md5 = 2816550d02043b473438caaca65d963e OK 2025/03/06 01:54:12 DEBUG : dst/three.txt: md5 = c8370228edf978331349ea761448d160 OK 2025/03/06 01:54:12 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-yowelix7taho/dst" 2025/03/06 01:54:12 DEBUG : Creating backend with remote "TestDrive:crypt/bi3hem14btfb1nqq3d26d65889gu06un3tb12s4cc9d4a0j3cgu0/31u3jie661vd5p8j7rtc3hgbh0" 2025/03/06 01:54:13 DEBUG : one: Sizes differ (src 4 vs dst 3) 2025/03/06 01:54:14 INFO : one: Moved (server-side) to: one-2019-01-01 2025/03/06 01:54:16 DEBUG : one: md5 = d516941d50975537d1a0eaf7b9cd1078 OK 2025/03/06 01:54:16 INFO : one: Copied (new) 2025/03/06 01:54:16 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/03/06 01:54:16 DEBUG : two: Unchanged skipping 2025/03/06 01:54:16 DEBUG : three.txt: Sizes differ (src 6 vs dst 5) 2025/03/06 01:54:17 INFO : three.txt: Moved (server-side) to: three-2019-01-01.txt 2025/03/06 01:54:18 DEBUG : three.txt: md5 = 3d74a6ef91c9548ad8a7d14f80a65bab OK 2025/03/06 01:54:18 INFO : three.txt: Copied (new) 2025/03/06 01:54:20 DEBUG : one: Sizes differ (src 5 vs dst 4) 2025/03/06 01:54:20 INFO : one-2019-01-01: Deleted 2025/03/06 01:54:21 INFO : one: Moved (server-side) to: one-2019-01-01 2025/03/06 01:54:22 DEBUG : one: md5 = e6cc929a155d2c1f05749db0919a136c OK 2025/03/06 01:54:22 INFO : one: Copied (new) 2025/03/06 01:54:22 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/03/06 01:54:22 DEBUG : two: Unchanged skipping 2025/03/06 01:54:23 DEBUG : three.txt: Sizes differ (src 19 vs dst 6) 2025/03/06 01:54:23 INFO : three-2019-01-01.txt: Deleted 2025/03/06 01:54:24 INFO : three.txt: Moved (server-side) to: three-2019-01-01.txt 2025/03/06 01:54:25 DEBUG : three.txt: md5 = ee4c8979593d4f202b54b30f32cacd88 OK 2025/03/06 01:54:25 INFO : three.txt: Copied (new) 2025/03/06 01:54:29 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" 2025/03/06 01:54:29 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "tr2hj63d80ftlmvm6a952snjcc" 2025/03/06 01:54:29 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "jcjl1bv3ep0v8kt35lqql1co90" 2025/03/06 01:54:29 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "qtq2f6qq4lgpsmj88vb7147qje3prudmtfdtr2342fth58vo9a50" 2025/03/06 01:54:29 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "qtq2f6qq4lgpsmj88vb7147qje3prudmtfdtr2342fth58vo9a50" 2025/03/06 01:54:29 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k" 2025/03/06 01:54:29 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "jcjl1bv3ep0v8kt35lqql1co90" --- PASS: TestSyncSuffixKeepExtension (22.54s) === RUN TestSyncUTFNorm run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-yowelix7taho'", Local "Local file system at /tmp/rclone3247573043", Modify Window "1ms" 2025/03/06 01:54:31 DEBUG : Testêé: md5 = fab9e53a5af8f8d5cf7c989c2913f7f9 OK 2025/03/06 01:54:31 DEBUG : Testêé: Sizes differ (src 14 vs dst 18) 2025/03/06 01:54:31 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yowelix7taho': Waiting for checks to finish 2025/03/06 01:54:31 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yowelix7taho': Waiting for transfers to finish 2025/03/06 01:54:33 DEBUG : Testêé: md5 = fed766c6a34b9e875f0bf81c2be72f30 OK 2025/03/06 01:54:33 INFO : Testêé: Copied (replaced existing) to: Testêé 2025/03/06 01:54:33 DEBUG : Waiting for deletions to finish --- PASS: TestSyncUTFNorm (4.41s) === RUN TestSyncImmutable run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-yowelix7taho'", Local "Local file system at /tmp/rclone3247573043", Modify Window "1ms" 2025/03/06 01:54:34 DEBUG : existing: Need to transfer - File not found at Destination 2025/03/06 01:54:34 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yowelix7taho': Waiting for checks to finish 2025/03/06 01:54:34 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yowelix7taho': Waiting for transfers to finish 2025/03/06 01:54:36 DEBUG : existing: md5 = 259277170921908140e8e9d98bb771b3 OK 2025/03/06 01:54:36 INFO : existing: Copied (new) 2025/03/06 01:54:36 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-yowelix7taho'", Local "Local file system at /tmp/rclone3247573043", Modify Window "1ms" 2025/03/06 01:54:36 DEBUG : existing: Sizes differ (src 8 vs dst 6) 2025/03/06 01:54:36 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yowelix7taho': Waiting for checks to finish 2025/03/06 01:54:36 ERROR : existing: Source and destination exist but do not match: immutable file modified 2025/03/06 01:54:36 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yowelix7taho': Waiting for transfers to finish 2025/03/06 01:54:36 ERROR : Encrypted drive 'TestCryptDrive:rclone-test-yowelix7taho': not deleting files as there were IO errors 2025/03/06 01:54:36 ERROR : Encrypted drive 'TestCryptDrive:rclone-test-yowelix7taho': not deleting directories as there were IO errors run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-yowelix7taho'", Local "Local file system at /tmp/rclone3247573043", Modify Window "1ms" --- PASS: TestSyncImmutable (4.89s) === RUN TestSyncIgnoreCase run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-yowelix7taho'", Local "Local file system at /tmp/rclone3247573043", Modify Window "1ms" 2025/03/06 01:54:40 DEBUG : EXISTING: md5 = 3558d47bc07836f2975fd30453c332a6 OK 2025/03/06 01:54:41 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yowelix7taho': Waiting for checks to finish 2025/03/06 01:54:41 DEBUG : existing: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/03/06 01:54:41 DEBUG : existing: Unchanged skipping 2025/03/06 01:54:41 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yowelix7taho': Waiting for transfers to finish 2025/03/06 01:54:41 DEBUG : Waiting for deletions to finish 2025/03/06 01:54:41 INFO : There was nothing to transfer --- PASS: TestSyncIgnoreCase (3.03s) === RUN TestFixCase run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-yowelix7taho'", Local "Local file system at /tmp/rclone3247573043", Modify Window "1ms" sync_test.go:2635: Skipping test as local or remote are case-sensitive --- SKIP: TestFixCase (0.46s) === RUN TestMaxTransfer === RUN TestMaxTransfer/Hard run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-yowelix7taho'", Local "Local file system at /tmp/rclone3247573043", 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-yowelix7taho'", Local "Local file system at /tmp/rclone3247573043", 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-yowelix7taho'", Local "Local file system at /tmp/rclone3247573043", Modify Window "1ms" sync_test.go:2674: This test only runs on local --- PASS: TestMaxTransfer (1.33s) --- SKIP: TestMaxTransfer/Hard (0.43s) --- SKIP: TestMaxTransfer/Soft (0.45s) --- SKIP: TestMaxTransfer/Cautious (0.45s) === RUN TestSyncConcurrentDelete run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-yowelix7taho'", Local "Local file system at /tmp/rclone3247573043", Modify Window "1ms" 2025/03/06 01:54:45 DEBUG : both0: md5 = d80829b5682e391ad93b2d95ce69e283 OK 2025/03/06 01:54:46 DEBUG : only0: md5 = 435346d8e2fc5cc38f3410b48dd61aed OK 2025/03/06 01:54:47 DEBUG : both1: md5 = eebe7649ea7975ecbedb9cd84867a047 OK 2025/03/06 01:54:49 DEBUG : only1: md5 = 9982c09fa51edab465d7a57a324ff770 OK 2025/03/06 01:54:50 DEBUG : both2: md5 = 7eebafbc6ab66b8c240defc353af9f76 OK 2025/03/06 01:54:52 DEBUG : only2: md5 = 70fee849904a89cf3a9a1351083a6fbc OK 2025/03/06 01:54:53 DEBUG : both3: md5 = 5d3f16b8fa2f4635eb7228bb6bc397a6 OK 2025/03/06 01:54:55 DEBUG : only3: md5 = 7dd18904792581b6982b64f4692091bf OK 2025/03/06 01:54:56 DEBUG : both4: md5 = 73fb8256b0af30ba69d1cea465efb699 OK 2025/03/06 01:54:57 DEBUG : only4: md5 = 46ef39674538bb3b37b2ab03abe49d3e OK 2025/03/06 01:54:59 DEBUG : both5: md5 = c52c95776bf5d37d0e22f267f404befe OK 2025/03/06 01:55:00 DEBUG : only5: md5 = aa3496b6fe6032c28c062e9c25df8910 OK 2025/03/06 01:55:02 DEBUG : both6: md5 = d7e865a36a8ece4220d2b23105dde2ab OK 2025/03/06 01:55:03 DEBUG : only6: md5 = d87caeab9ed8e5fc60338e25fa4ddd49 OK 2025/03/06 01:55:04 DEBUG : both7: md5 = dc9cc18a236886bf5b835329a7b6a07a OK 2025/03/06 01:55:06 DEBUG : only7: md5 = a1070d1e34dd614ba817c75943346c3c OK 2025/03/06 01:55:07 DEBUG : both8: md5 = 003a203c00d723b47bd8aae61cccb24d OK 2025/03/06 01:55:09 DEBUG : only8: md5 = 0f9cd113c20661735f254b5d379b39a5 OK 2025/03/06 01:55:10 DEBUG : both9: md5 = 3e3e6b275c83690e1ab023ea5b77014a OK 2025/03/06 01:55:12 DEBUG : only9: md5 = feeb948e62b8b0d4709d94a434042c98 OK 2025/03/06 01:55:13 DEBUG : both10: md5 = 46ef7feb297aa6fbcd6046f68eec156c OK 2025/03/06 01:55:14 DEBUG : only10: md5 = 56239bb7fecd8f1398e274116e803727 OK 2025/03/06 01:55:16 DEBUG : both11: md5 = 5c0c95a331823114972a65f50689b1d0 OK 2025/03/06 01:55:17 DEBUG : only11: md5 = 6fc7a22b62f016c7e480f78e1fd2f153 OK 2025/03/06 01:55:19 DEBUG : both12: md5 = 14691b98d916a05b9c288c5cfdea3df0 OK 2025/03/06 01:55:20 DEBUG : only12: md5 = e93da7c9098911f9cb0353025f982522 OK 2025/03/06 01:55:22 DEBUG : both13: md5 = 96ef5bcb8ffaa925a434a821b96e0b3d OK 2025/03/06 01:55:23 DEBUG : only13: md5 = e18a192118aaf6046705d7dc7c3b8dac OK 2025/03/06 01:55:24 DEBUG : both14: md5 = e5ca36fa309df5ed56c4bef638c0dd7b OK 2025/03/06 01:55:26 DEBUG : only14: md5 = 08dfa2967cbbb830f304b1a816e6885a OK 2025/03/06 01:55:27 DEBUG : both15: md5 = 0dc29ba630c1d7a2c2990ad64e089997 OK 2025/03/06 01:55:29 DEBUG : only15: md5 = e133f03a9515a68135ab352b17fbfd9e OK 2025/03/06 01:55:30 DEBUG : both16: md5 = 03ebdd68ab48b38c6e237213e654cb53 OK 2025/03/06 01:55:31 DEBUG : only16: md5 = 0e0bc1ea78116c56daf77838e6b7a92f OK 2025/03/06 01:55:33 DEBUG : both17: md5 = 36102acc3c69fc4b0dafe490f00498f9 OK 2025/03/06 01:55:34 DEBUG : only17: md5 = 6c3ab5f0728cc51dbf3dfa11af8e78f9 OK 2025/03/06 01:55:36 DEBUG : both18: md5 = 4ebeea551c9dcc2ba822238a8aed19a3 OK 2025/03/06 01:55:37 DEBUG : only18: md5 = 3cd89b408142b237d4f8210d1f0accef OK 2025/03/06 01:55:38 DEBUG : both19: md5 = 506ec05c60d424554b7fb87ab121581f OK 2025/03/06 01:55:40 DEBUG : only19: md5 = 6e342aeb2367584241fa55ff82d224b0 OK 2025/03/06 01:55:40 DEBUG : both0: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/03/06 01:55:40 DEBUG : both0: Unchanged skipping 2025/03/06 01:55:40 DEBUG : both1: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/03/06 01:55:40 DEBUG : both1: Unchanged skipping 2025/03/06 01:55:40 DEBUG : both10: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/03/06 01:55:40 DEBUG : both10: Unchanged skipping 2025/03/06 01:55:40 DEBUG : both11: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/03/06 01:55:40 DEBUG : both11: Unchanged skipping 2025/03/06 01:55:40 DEBUG : both12: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/03/06 01:55:40 DEBUG : both12: Unchanged skipping 2025/03/06 01:55:40 DEBUG : both13: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/03/06 01:55:40 DEBUG : both13: Unchanged skipping 2025/03/06 01:55:40 DEBUG : both14: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/03/06 01:55:40 DEBUG : both14: Unchanged skipping 2025/03/06 01:55:40 DEBUG : both15: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/03/06 01:55:40 DEBUG : both15: Unchanged skipping 2025/03/06 01:55:40 DEBUG : both16: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/03/06 01:55:40 DEBUG : both16: Unchanged skipping 2025/03/06 01:55:40 DEBUG : both17: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/03/06 01:55:40 DEBUG : both17: Unchanged skipping 2025/03/06 01:55:40 DEBUG : both18: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/03/06 01:55:40 DEBUG : both18: Unchanged skipping 2025/03/06 01:55:40 DEBUG : both19: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/03/06 01:55:40 DEBUG : both19: Unchanged skipping 2025/03/06 01:55:40 DEBUG : both2: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/03/06 01:55:40 DEBUG : both2: Unchanged skipping 2025/03/06 01:55:40 DEBUG : both3: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/03/06 01:55:40 DEBUG : both3: Unchanged skipping 2025/03/06 01:55:40 DEBUG : both4: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/03/06 01:55:40 DEBUG : both4: Unchanged skipping 2025/03/06 01:55:40 DEBUG : both5: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/03/06 01:55:40 DEBUG : both5: Unchanged skipping 2025/03/06 01:55:40 DEBUG : both6: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/03/06 01:55:40 DEBUG : both6: Unchanged skipping 2025/03/06 01:55:40 DEBUG : both7: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/03/06 01:55:40 DEBUG : both7: Unchanged skipping 2025/03/06 01:55:40 DEBUG : both8: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/03/06 01:55:40 DEBUG : both8: Unchanged skipping 2025/03/06 01:55:40 DEBUG : both9: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/03/06 01:55:40 DEBUG : both9: Unchanged skipping 2025/03/06 01:55:40 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yowelix7taho': Waiting for checks to finish 2025/03/06 01:55:40 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yowelix7taho': Waiting for transfers to finish 2025/03/06 01:55:40 DEBUG : Waiting for deletions to finish 2025/03/06 01:55:41 INFO : only10: Deleted 2025/03/06 01:55:41 INFO : only18: Deleted 2025/03/06 01:55:41 INFO : only3: Deleted 2025/03/06 01:55:41 INFO : only17: Deleted 2025/03/06 01:55:41 INFO : only15: Deleted 2025/03/06 01:55:41 INFO : only11: Deleted 2025/03/06 01:55:41 INFO : only14: Deleted 2025/03/06 01:55:41 INFO : only16: Deleted 2025/03/06 01:55:42 INFO : only4: Deleted 2025/03/06 01:55:42 INFO : only12: Deleted 2025/03/06 01:55:42 INFO : only7: Deleted 2025/03/06 01:55:42 INFO : only13: Deleted 2025/03/06 01:55:42 INFO : only9: Deleted 2025/03/06 01:55:42 INFO : only0: Deleted 2025/03/06 01:55:42 INFO : only1: Deleted 2025/03/06 01:55:42 INFO : only2: Deleted 2025/03/06 01:55:43 INFO : only6: Deleted 2025/03/06 01:55:43 INFO : only19: Deleted 2025/03/06 01:55:43 INFO : only5: Deleted 2025/03/06 01:55:43 INFO : only8: Deleted 2025/03/06 01:55:43 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-yowelix7taho'", Local "Local file system at /tmp/rclone3247573043", Modify Window "1ms" --- PASS: TestSyncConcurrentDelete (70.19s) === RUN TestSyncConcurrentTruncate run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-yowelix7taho'", Local "Local file system at /tmp/rclone3247573043", Modify Window "1ms" 2025/03/06 01:55:55 DEBUG : both0: md5 = a7d7c59e56e61a89599f3548fdf9d1ed OK 2025/03/06 01:55:56 DEBUG : only0: md5 = 1520877349be299bb1c39a31f4ca4bd3 OK 2025/03/06 01:55:58 DEBUG : both1: md5 = 80905ae5dd87208b932e0db3a3b432fb OK 2025/03/06 01:55:59 DEBUG : only1: md5 = 4dc5bd2312ae3566c83b4dcffe90fb9a OK 2025/03/06 01:56:01 DEBUG : both2: md5 = 3711ee2ea6b7320408b9dbdb5c0f32e7 OK 2025/03/06 01:56:02 DEBUG : only2: md5 = d6dc90718c19137accda4a581476ff73 OK 2025/03/06 01:56:03 DEBUG : both3: md5 = bcad77f5fbad27778345ac7e7f45217a OK 2025/03/06 01:56:05 DEBUG : only3: md5 = 5cefe9e0d2dfb29b4d742c127f489e5a OK 2025/03/06 01:56:06 DEBUG : both4: md5 = 0ac62f6600f19820b5ccfac5e25ed86a OK 2025/03/06 01:56:08 DEBUG : only4: md5 = 3210f72729c519d354cf74c9f757831c OK 2025/03/06 01:56:10 DEBUG : both5: md5 = 2791e23312f1783894e7d878d21fb07b OK 2025/03/06 01:56:11 DEBUG : only5: md5 = 129c6625938d7baeb0870663da797696 OK 2025/03/06 01:56:13 DEBUG : both6: md5 = 930971008efecf08b17af82c28ff1696 OK 2025/03/06 01:56:14 DEBUG : only6: md5 = 2306331ff13688aa30a3186499c18f72 OK 2025/03/06 01:56:16 DEBUG : both7: md5 = 1415958d41ca166b971c92eea9c86ba1 OK 2025/03/06 01:56:17 DEBUG : only7: md5 = 7c1aa9b9fc8e2f9ae07943ce33535298 OK 2025/03/06 01:56:18 DEBUG : both8: md5 = 5a6da7bb1be0f3db56e49f99c7ad4bee OK 2025/03/06 01:56:20 DEBUG : only8: md5 = 5d137fdaab7b45ad2ae4e7176c925fab OK 2025/03/06 01:56:21 DEBUG : both9: md5 = 716bba0f1fec57d2e2dd830ac233b635 OK 2025/03/06 01:56:23 DEBUG : only9: md5 = b47359a6496aa6d34b863ee0a902194e OK 2025/03/06 01:56:24 DEBUG : both10: md5 = 1a3652f236cb4ad6bd9cb5e4d09b8266 OK 2025/03/06 01:56:25 DEBUG : only10: md5 = 1808df31337bc66f931ea99a049d5fe2 OK 2025/03/06 01:56:27 DEBUG : both11: md5 = 46572a9d7d1468c1e55daa0cee1f35bf OK 2025/03/06 01:56:28 DEBUG : only11: md5 = bec904d6c566acc4a74953a24e620e83 OK 2025/03/06 01:56:29 DEBUG : both12: md5 = 9a1cc455e629979476d6806588060896 OK 2025/03/06 01:56:31 DEBUG : only12: md5 = 37ce0f6df783fe4e3345846b40d93c2d OK 2025/03/06 01:56:32 DEBUG : both13: md5 = db7f7a97b8073818b66964de5dbe2058 OK 2025/03/06 01:56:34 DEBUG : only13: md5 = 7612d1955103a06c86fdea2af7888d02 OK 2025/03/06 01:56:35 DEBUG : both14: md5 = b10337b33b60064ad1b20e6c53173629 OK 2025/03/06 01:56:36 DEBUG : only14: md5 = 03b54ecbebf4c38c7570edc5cdd7690f OK 2025/03/06 01:56:38 DEBUG : both15: md5 = 42042e8a10ed3c0b35c7a6e848f06aa4 OK 2025/03/06 01:56:39 DEBUG : only15: md5 = 83dd8eb9ddf878e818ee35fc94ca44d3 OK 2025/03/06 01:56:41 DEBUG : both16: md5 = 6127486ac23113c2cb92baa7792ab770 OK 2025/03/06 01:56:42 DEBUG : only16: md5 = b66be9959b1b6f903c0ab96f5de956d7 OK 2025/03/06 01:56:44 DEBUG : both17: md5 = 9420ddfc375c6ba19c62cb4ef00c34df OK 2025/03/06 01:56:45 DEBUG : only17: md5 = 1dc168ad11ba6211510f5c200339b9b1 OK 2025/03/06 01:56:46 DEBUG : both18: md5 = c3616b34f95aa401c628ba36cd28665c OK 2025/03/06 01:56:48 DEBUG : only18: md5 = 6585f246be887a859cac3b64d103c99c OK 2025/03/06 01:56:49 DEBUG : both19: md5 = 2b4980853d6ce90f752740b8f72eaf92 OK 2025/03/06 01:56:50 DEBUG : only19: md5 = 96c57558442fa4e16a6d592924955c44 OK 2025/03/06 01:56:51 DEBUG : both0: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/03/06 01:56:51 DEBUG : both0: Unchanged skipping 2025/03/06 01:56:51 DEBUG : both11: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/03/06 01:56:51 DEBUG : both10: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/03/06 01:56:51 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yowelix7taho': Waiting for checks to finish 2025/03/06 01:56:51 DEBUG : both12: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/03/06 01:56:51 DEBUG : both1: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/03/06 01:56:51 DEBUG : both11: Unchanged skipping 2025/03/06 01:56:51 DEBUG : both13: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/03/06 01:56:51 DEBUG : both1: Unchanged skipping 2025/03/06 01:56:51 DEBUG : both14: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/03/06 01:56:51 DEBUG : both10: Unchanged skipping 2025/03/06 01:56:51 DEBUG : both15: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/03/06 01:56:51 DEBUG : both15: Unchanged skipping 2025/03/06 01:56:51 DEBUG : both16: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/03/06 01:56:51 DEBUG : both12: Unchanged skipping 2025/03/06 01:56:51 DEBUG : both17: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/03/06 01:56:51 DEBUG : both17: Unchanged skipping 2025/03/06 01:56:51 DEBUG : both18: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/03/06 01:56:51 DEBUG : both13: Unchanged skipping 2025/03/06 01:56:51 DEBUG : both19: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/03/06 01:56:51 DEBUG : both19: Unchanged skipping 2025/03/06 01:56:51 DEBUG : both2: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/03/06 01:56:51 DEBUG : both2: Unchanged skipping 2025/03/06 01:56:51 DEBUG : both3: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/03/06 01:56:51 DEBUG : both3: Unchanged skipping 2025/03/06 01:56:51 DEBUG : both4: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/03/06 01:56:51 DEBUG : both4: Unchanged skipping 2025/03/06 01:56:51 DEBUG : both5: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/03/06 01:56:51 DEBUG : both5: Unchanged skipping 2025/03/06 01:56:51 DEBUG : both6: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/03/06 01:56:51 DEBUG : both6: Unchanged skipping 2025/03/06 01:56:51 DEBUG : both7: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/03/06 01:56:51 DEBUG : both7: Unchanged skipping 2025/03/06 01:56:51 DEBUG : both8: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/03/06 01:56:51 DEBUG : both8: Unchanged skipping 2025/03/06 01:56:51 DEBUG : both9: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/03/06 01:56:51 DEBUG : both9: Unchanged skipping 2025/03/06 01:56:51 DEBUG : only0: Sizes differ (src 0 vs dst 6) 2025/03/06 01:56:51 DEBUG : only1: Sizes differ (src 0 vs dst 6) 2025/03/06 01:56:51 DEBUG : only10: Sizes differ (src 0 vs dst 6) 2025/03/06 01:56:51 DEBUG : only11: Sizes differ (src 0 vs dst 6) 2025/03/06 01:56:51 DEBUG : only12: Sizes differ (src 0 vs dst 6) 2025/03/06 01:56:51 DEBUG : only13: Sizes differ (src 0 vs dst 6) 2025/03/06 01:56:51 DEBUG : only14: Sizes differ (src 0 vs dst 6) 2025/03/06 01:56:51 DEBUG : only15: Sizes differ (src 0 vs dst 6) 2025/03/06 01:56:51 DEBUG : only16: Sizes differ (src 0 vs dst 6) 2025/03/06 01:56:51 DEBUG : only17: Sizes differ (src 0 vs dst 6) 2025/03/06 01:56:51 DEBUG : only18: Sizes differ (src 0 vs dst 6) 2025/03/06 01:56:51 DEBUG : only19: Sizes differ (src 0 vs dst 6) 2025/03/06 01:56:51 DEBUG : only2: Sizes differ (src 0 vs dst 6) 2025/03/06 01:56:51 DEBUG : only3: Sizes differ (src 0 vs dst 6) 2025/03/06 01:56:51 DEBUG : only4: Sizes differ (src 0 vs dst 6) 2025/03/06 01:56:51 DEBUG : only5: Sizes differ (src 0 vs dst 6) 2025/03/06 01:56:51 DEBUG : only6: Sizes differ (src 0 vs dst 6) 2025/03/06 01:56:51 DEBUG : only7: Sizes differ (src 0 vs dst 6) 2025/03/06 01:56:51 DEBUG : only8: Sizes differ (src 0 vs dst 6) 2025/03/06 01:56:51 DEBUG : only9: Sizes differ (src 0 vs dst 6) 2025/03/06 01:56:51 DEBUG : both14: Unchanged skipping 2025/03/06 01:56:51 DEBUG : both16: Unchanged skipping 2025/03/06 01:56:51 DEBUG : both18: Unchanged skipping 2025/03/06 01:56:51 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yowelix7taho': Waiting for transfers to finish 2025/03/06 01:56:52 DEBUG : only0: md5 = 5eac4fbe83c5737cf57c1c5354db5fdb OK 2025/03/06 01:56:52 INFO : only0: Copied (replaced existing) 2025/03/06 01:56:52 DEBUG : only10: md5 = 518f20e9219f0371eff3ef36ed781f0f OK 2025/03/06 01:56:52 INFO : only10: Copied (replaced existing) 2025/03/06 01:56:52 DEBUG : only1: md5 = 793f7ad50d253c7000ff0eb0a1eb0ffb OK 2025/03/06 01:56:52 INFO : only1: Copied (replaced existing) 2025/03/06 01:56:52 DEBUG : only11: md5 = 54a86acdc5e66686b9113e90e6ab374a OK 2025/03/06 01:56:52 INFO : only11: Copied (replaced existing) 2025/03/06 01:56:53 DEBUG : only13: md5 = bac0ef0416c48ec29386b557d3c62c36 OK 2025/03/06 01:56:53 INFO : only13: Copied (replaced existing) 2025/03/06 01:56:53 DEBUG : only12: md5 = 4077f4cb92d5194365f11209841440a1 OK 2025/03/06 01:56:53 INFO : only12: Copied (replaced existing) 2025/03/06 01:56:53 DEBUG : only15: md5 = 656c52c73f75faa2f4e3b4d1709a65f6 OK 2025/03/06 01:56:53 INFO : only15: Copied (replaced existing) 2025/03/06 01:56:53 DEBUG : only14: md5 = 8da700e040582a8a7ffa46dbc55022fc OK 2025/03/06 01:56:53 INFO : only14: Copied (replaced existing) 2025/03/06 01:56:55 DEBUG : only17: md5 = e670d04ab6b60b8e176562142a403869 OK 2025/03/06 01:56:55 INFO : only17: Copied (replaced existing) 2025/03/06 01:56:55 DEBUG : only19: md5 = 68d63928561952f5d106512f70dc6eae OK 2025/03/06 01:56:55 INFO : only19: Copied (replaced existing) 2025/03/06 01:56:55 DEBUG : only18: md5 = 18b15edd38e8a6da8a7e77cfcdf6b434 OK 2025/03/06 01:56:55 INFO : only18: Copied (replaced existing) 2025/03/06 01:56:55 DEBUG : only16: md5 = 5c0e89e6f799ec579c6d9e9ae4a84f03 OK 2025/03/06 01:56:55 INFO : only16: Copied (replaced existing) 2025/03/06 01:56:56 DEBUG : only2: md5 = f7b772738c51001799fbcc30c37def1c OK 2025/03/06 01:56:56 INFO : only2: Copied (replaced existing) 2025/03/06 01:56:56 DEBUG : only4: md5 = 19abfe618bbcf25736805c44d34f37f5 OK 2025/03/06 01:56:56 INFO : only4: Copied (replaced existing) 2025/03/06 01:56:56 DEBUG : only3: md5 = 7f0c0ebaa7b49cff8a7d5fae8139015a OK 2025/03/06 01:56:56 INFO : only3: Copied (replaced existing) 2025/03/06 01:56:56 DEBUG : only5: md5 = b9d935e9b2a0bec045f9e09de09d8b2c OK 2025/03/06 01:56:56 INFO : only5: Copied (replaced existing) 2025/03/06 01:56:57 DEBUG : only6: md5 = 27c32c6bbaae547bd0731fac282d56c5 OK 2025/03/06 01:56:57 INFO : only6: Copied (replaced existing) 2025/03/06 01:56:57 DEBUG : only8: md5 = 939a2e976875ef48f846a21e5220afec OK 2025/03/06 01:56:57 INFO : only8: Copied (replaced existing) 2025/03/06 01:56:57 DEBUG : only7: md5 = 2fca503a93a26e6f2ca5f43661dc712c OK 2025/03/06 01:56:57 INFO : only7: Copied (replaced existing) 2025/03/06 01:56:57 DEBUG : only9: md5 = ebdc99450dae0ac5be073b602dbdae78 OK 2025/03/06 01:56:57 INFO : only9: Copied (replaced existing) 2025/03/06 01:56:57 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-yowelix7taho'", Local "Local file system at /tmp/rclone3247573043", Modify Window "1ms" --- PASS: TestSyncConcurrentTruncate (82.82s) === RUN TestSyncReplaceDirModTime run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-yowelix7taho'", Local "Local file system at /tmp/rclone3247573043", Modify Window "1ms" 2025/03/06 01:57:17 DEBUG : empty_dir: Making directory with metadata 2025/03/06 01:57:17 INFO : empty_dir: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2025/03/06 01:57:17 DEBUG : empty_on_remote: Making directory with metadata 2025/03/06 01:57:17 INFO : empty_on_remote: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2025/03/06 01:57:17 DEBUG : empty_on_remote: Making directory with metadata 2025/03/06 01:57:17 INFO : empty_on_remote: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-yowelix7taho'", Local "Local file system at /tmp/rclone3247573043", Modify Window "1ms" 2025/03/06 01:57:23 INFO : test_dir1: Set directory modification time (using DirSetModTime) 2025/03/06 01:57:23 INFO : test_dir2: Set directory modification time (using DirSetModTime) 2025/03/06 01:57:23 INFO : test_dir2/sub_dir: Set directory modification time (using DirSetModTime) 2025/03/06 01:57:23 INFO : empty_on_remote: Set directory modification time (using DirSetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-yowelix7taho'", Local "Local file system at /tmp/rclone3247573043", Modify Window "1ms" 2025/03/06 01:57:30 DEBUG : heqj02jg0dcqlem7gl0500bvp0/24g2k8bseitblkmqnie1ibl2s8: Rmdir: contains trashed file: "633fmaa0qic3kv3cladnu11pto" 2025/03/06 01:57:30 DEBUG : heqj02jg0dcqlem7gl0500bvp0: Rmdir: contains trashed file: "24g2k8bseitblkmqnie1ibl2s8" 2025/03/06 01:57:31 DEBUG : gq68srrpl0nnf394bgf7dbu9kc: Rmdir: contains trashed file: "d26uovf0miqhd1mu3c9jbseq00" --- PASS: TestSyncReplaceDirModTime (16.72s) === RUN TestSyncReplaceDirModTimeWithEmptyDirs run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-yowelix7taho'", Local "Local file system at /tmp/rclone3247573043", Modify Window "1ms" 2025/03/06 01:57:33 DEBUG : empty_dir: Making directory with metadata 2025/03/06 01:57:33 INFO : empty_dir: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2025/03/06 01:57:33 DEBUG : empty_on_remote: Making directory with metadata 2025/03/06 01:57:33 INFO : empty_on_remote: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2025/03/06 01:57:33 DEBUG : empty_on_remote: Making directory with metadata 2025/03/06 01:57:34 INFO : empty_on_remote: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-yowelix7taho'", Local "Local file system at /tmp/rclone3247573043", Modify Window "1ms" 2025/03/06 01:57:39 INFO : test_dir1: Set directory modification time (using DirSetModTime) 2025/03/06 01:57:39 INFO : test_dir2: Set directory modification time (using DirSetModTime) 2025/03/06 01:57:39 INFO : test_dir2/sub_dir: Set directory modification time (using DirSetModTime) 2025/03/06 01:57:39 INFO : empty_on_remote: Set directory modification time (using DirSetModTime) 2025/03/06 01:57:39 INFO : empty_dir: Set directory modification time (using DirSetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-yowelix7taho'", Local "Local file system at /tmp/rclone3247573043", Modify Window "1ms" 2025/03/06 01:57:46 DEBUG : heqj02jg0dcqlem7gl0500bvp0/24g2k8bseitblkmqnie1ibl2s8: Rmdir: contains trashed file: "633fmaa0qic3kv3cladnu11pto" 2025/03/06 01:57:47 DEBUG : heqj02jg0dcqlem7gl0500bvp0: Rmdir: contains trashed file: "24g2k8bseitblkmqnie1ibl2s8" 2025/03/06 01:57:48 DEBUG : gq68srrpl0nnf394bgf7dbu9kc: Rmdir: contains trashed file: "d26uovf0miqhd1mu3c9jbseq00" --- PASS: TestSyncReplaceDirModTimeWithEmptyDirs (17.36s) === RUN TestNothingToTransferWithEmptyDirs run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-yowelix7taho'", Local "Local file system at /tmp/rclone3247573043", Modify Window "1ms" 2025/03/06 01:57:51 INFO : sub dir: Set directory modification time (using DirSetModTime) 2025/03/06 01:57:51 DEBUG : sub dir: Making directory with metadata 2025/03/06 01:57:51 INFO : sub dir: Made directory with metadata (mtime=2011-12-30T12:59:59Z) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-yowelix7taho'", Local "Local file system at /tmp/rclone3247573043", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-yowelix7taho'", Local "Local file system at /tmp/rclone3247573043", Modify Window "1ms" 2025/03/06 01:58:10 INFO : sub dir2: Set directory modification time (using DirSetModTime) 2025/03/06 01:58:10 INFO : sub dir2: Set directory modification time (using DirSetModTime) 2025/03/06 01:58:10 INFO : sub dirEmpty/sub dirEmpty2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2025/03/06 01:58:10 INFO : sub dirEmpty: Set directory modification time (using DirSetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-yowelix7taho'", Local "Local file system at /tmp/rclone3247573043", Modify Window "1ms" 2025/03/06 01:58:22 DEBUG : gcsdkq814sbtppue42dpsbg8ug: Rmdir: contains trashed file: "sjuo65gk5q3r1199jselk9k9o0" 2025/03/06 01:58:23 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/37qp6d1gohacv723ij3brofbu8/i24n0ln37pa2hv8pctddeuh73o: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" 2025/03/06 01:58:24 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/37qp6d1gohacv723ij3brofbu8: Rmdir: contains trashed file: "i24n0ln37pa2hv8pctddeuh73o" 2025/03/06 01:58:24 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "37qp6d1gohacv723ij3brofbu8" 2025/03/06 01:58:25 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak" 2025/03/06 01:58:26 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak" 2025/03/06 01:58:26 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak" 2025/03/06 01:58:27 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak" 2025/03/06 01:58:28 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/4r13oncfa2rsrr82oqhsqv24ns: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" 2025/03/06 01:58:28 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc: Rmdir: contains trashed file: "4r13oncfa2rsrr82oqhsqv24ns" 2025/03/06 01:58:28 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak" 2025/03/06 01:58:29 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestNothingToTransferWithEmptyDirs (40.48s) === RUN TestNothingToTransferWithoutEmptyDirs run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-yowelix7taho'", Local "Local file system at /tmp/rclone3247573043", Modify Window "1ms" 2025/03/06 01:58:31 INFO : sub dir: Set directory modification time (using DirSetModTime) 2025/03/06 01:58:31 DEBUG : sub dir: Making directory with metadata 2025/03/06 01:58:32 INFO : sub dir: Made directory with metadata (mtime=2011-12-30T12:59:59Z) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-yowelix7taho'", Local "Local file system at /tmp/rclone3247573043", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-yowelix7taho'", Local "Local file system at /tmp/rclone3247573043", Modify Window "1ms" 2025/03/06 01:58:53 INFO : sub dir2: Set directory modification time (using DirSetModTime) 2025/03/06 01:58:54 INFO : sub dir2: Set directory modification time (using DirSetModTime) 2025/03/06 01:58:54 INFO : sub dirEmpty/sub dirEmpty2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2025/03/06 01:58:54 INFO : sub dirEmpty: Set directory modification time (using DirSetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-yowelix7taho'", Local "Local file system at /tmp/rclone3247573043", Modify Window "1ms" 2025/03/06 01:59:05 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/37qp6d1gohacv723ij3brofbu8/i24n0ln37pa2hv8pctddeuh73o: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" 2025/03/06 01:59:06 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/37qp6d1gohacv723ij3brofbu8: Rmdir: contains trashed file: "i24n0ln37pa2hv8pctddeuh73o" 2025/03/06 01:59:07 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "37qp6d1gohacv723ij3brofbu8" 2025/03/06 01:59:07 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak" 2025/03/06 01:59:08 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak" 2025/03/06 01:59:09 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak" 2025/03/06 01:59:09 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak" 2025/03/06 01:59:10 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/4r13oncfa2rsrr82oqhsqv24ns: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" 2025/03/06 01:59:11 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc: Rmdir: contains trashed file: "4r13oncfa2rsrr82oqhsqv24ns" 2025/03/06 01:59:11 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak" 2025/03/06 01:59:12 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestNothingToTransferWithoutEmptyDirs (42.50s) PASS 2025/03/06 01:59:14 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yowelix7taho': Purge remote "./sync.test -test.v -test.timeout 1h0m0s -remote TestCryptDrive: -verbose" - Finished OK in 15m41.481952052s (try 1/5)