"./sync.test -test.v -test.timeout 1h0m0s -remote TestCryptDrive: -verbose -fast-list" - Starting (try 1/5) 2025/03/11 07:24:43 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-pefewaw2dupe" 2025/03/11 07:24:43 DEBUG : Using config file from "/home/rclone/.rclone.conf" 2025/03/11 07:24:43 DEBUG : Creating backend with remote "TestDrive:crypt/ksagmlv3rj5m8b0msrmbqotspumdk55608q89rcqpeo8k9oluq3g" 2025/03/11 07:24:44 DEBUG : Creating backend with remote "/tmp/rclone22493455" === RUN TestPipe --- PASS: TestPipe (0.00s) === RUN TestPipeConcurrent --- PASS: TestPipeConcurrent (0.02s) === 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-pefewaw2dupe'", Local "Local file system at /tmp/rclone22493455", Modify Window "1ms" 2025/03/11 07:24:45 DEBUG : Added delayed dir = "sub dir", newDst= 2025/03/11 07:24:45 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2025/03/11 07:24:45 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pefewaw2dupe': Waiting for checks to finish 2025/03/11 07:24:45 NOTICE: sub dir/hello world: Skipped copy as --dry-run is set (size 11) 2025/03/11 07:24:45 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pefewaw2dupe': Waiting for transfers to finish 2025/03/11 07:24:45 NOTICE: sub dir: Skipped set directory modification time as --dry-run is set run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pefewaw2dupe'", Local "Local file system at /tmp/rclone22493455", Modify Window "1ms" --- PASS: TestCopyWithDryRun (2.22s) === RUN TestCopy run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pefewaw2dupe'", Local "Local file system at /tmp/rclone22493455", Modify Window "1ms" 2025/03/11 07:24:46 INFO : sub dir: Set directory modification time (using DirSetModTime) 2025/03/11 07:24:46 DEBUG : Added delayed dir = "sub dir", newDst= 2025/03/11 07:24:46 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2025/03/11 07:24:46 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pefewaw2dupe': Waiting for checks to finish 2025/03/11 07:24:46 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pefewaw2dupe': Waiting for transfers to finish 2025/03/11 07:24:49 DEBUG : sub dir/hello world: md5 = fbbf73604befcf55bb497cc28d28b5e0 OK 2025/03/11 07:24:49 INFO : sub dir/hello world: Copied (new) 2025/03/11 07:24:49 INFO : sub dir: Set directory modification time (using DirSetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pefewaw2dupe'", Local "Local file system at /tmp/rclone22493455", Modify Window "1ms" 2025/03/11 07:24:51 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestCopy (6.37s) === RUN TestCopyMetadata run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pefewaw2dupe'", Local "Local file system at /tmp/rclone22493455", Modify Window "1ms" 2025/03/11 07:24:53 DEBUG : metadata sub dir: Making directory with metadata 2025/03/11 07:24:53 INFO : metadata sub dir: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2025/03/11 07:24:53 DEBUG : empty metadata sub dir: Making directory with metadata 2025/03/11 07:24:53 INFO : empty metadata sub dir: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2025/03/11 07:24:53 DEBUG : Local file system at /tmp/rclone22493455: File to upload is small (21 bytes), uploading instead of streaming 2025/03/11 07:24:53 DEBUG : metadata sub dir/hello metadata world: md5 = baa7a013449dbba2b1ed02b5cfb4e1a2 OK 2025/03/11 07:24:53 DEBUG : metadata sub dir/hello metadata world: Size and md5 of src and dst objects identical 2025/03/11 07:24:53 INFO : metadata sub dir: Set directory modification time (using DirSetModTime) 2025/03/11 07:24:53 DEBUG : Google drive root 'crypt/ksagmlv3rj5m8b0msrmbqotspumdk55608q89rcqpeo8k9oluq3g': Skipping btime metadata as can't update it on an existing file: 2025-03-11T07:24:53.093894518Z 2025/03/11 07:24:54 INFO : empty metadata sub dir: Updated directory metadata 2025/03/11 07:24:54 DEBUG : Google drive root 'crypt/ksagmlv3rj5m8b0msrmbqotspumdk55608q89rcqpeo8k9oluq3g': Skipping btime metadata as can't update it on an existing file: 2025-03-11T07:24:53.08989453Z 2025/03/11 07:24:54 INFO : metadata sub dir: Updated directory metadata 2025/03/11 07:24:54 DEBUG : metadata sub dir/hello metadata world: Need to transfer - File not found at Destination 2025/03/11 07:24:54 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pefewaw2dupe': Waiting for checks to finish 2025/03/11 07:24:54 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pefewaw2dupe': Waiting for transfers to finish 2025/03/11 07:24:56 DEBUG : metadata sub dir/hello metadata world: md5 = fc3743e5f244d7f45d7e4a232876aa11 OK 2025/03/11 07:24:56 INFO : metadata sub dir/hello metadata world: Copied (new) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pefewaw2dupe'", Local "Local file system at /tmp/rclone22493455", Modify Window "1ms" 2025/03/11 07:24:59 DEBUG : fg45q1rm3kh00nmmkk4m6ihmrcnel1p7551kqhjr9bk2gtd2gbf0: Rmdir: contains trashed file: "dmuvulfij81f693ur0f1vvbvq9v6iscp56daas3m51n9li5e3470" --- PASS: TestCopyMetadata (7.83s) === RUN TestCopyMetadataNoEmptyDirs run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pefewaw2dupe'", Local "Local file system at /tmp/rclone22493455", Modify Window "1ms" 2025/03/11 07:25:00 DEBUG : metadata sub dir: Making directory with metadata 2025/03/11 07:25:00 INFO : metadata sub dir: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2025/03/11 07:25:00 DEBUG : empty metadata sub dir: Making directory with metadata 2025/03/11 07:25:00 INFO : empty metadata sub dir: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2025/03/11 07:25:00 DEBUG : Local file system at /tmp/rclone22493455: File to upload is small (21 bytes), uploading instead of streaming 2025/03/11 07:25:00 DEBUG : metadata sub dir/hello metadata world: md5 = baa7a013449dbba2b1ed02b5cfb4e1a2 OK 2025/03/11 07:25:00 DEBUG : metadata sub dir/hello metadata world: Size and md5 of src and dst objects identical 2025/03/11 07:25:00 INFO : metadata sub dir: Set directory modification time (using DirSetModTime) 2025/03/11 07:25:01 DEBUG : Added delayed dir = "empty metadata sub dir", newDst= 2025/03/11 07:25:01 DEBUG : Added delayed dir = "metadata sub dir", newDst= 2025/03/11 07:25:01 DEBUG : metadata sub dir/hello metadata world: Need to transfer - File not found at Destination 2025/03/11 07:25:01 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pefewaw2dupe': Waiting for checks to finish 2025/03/11 07:25:01 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pefewaw2dupe': Waiting for transfers to finish 2025/03/11 07:25:03 DEBUG : metadata sub dir/hello metadata world: md5 = 78e68559865722aad807a5fbc8e3542f OK 2025/03/11 07:25:03 INFO : metadata sub dir/hello metadata world: Copied (new) 2025/03/11 07:25:03 DEBUG : Google drive root 'crypt/ksagmlv3rj5m8b0msrmbqotspumdk55608q89rcqpeo8k9oluq3g': Skipping btime metadata as can't update it on an existing file: 2025-03-11T07:25:00.917870485Z 2025/03/11 07:25:04 INFO : metadata sub dir: Updated directory metadata run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pefewaw2dupe'", Local "Local file system at /tmp/rclone22493455", Modify Window "1ms" 2025/03/11 07:25:06 DEBUG : fg45q1rm3kh00nmmkk4m6ihmrcnel1p7551kqhjr9bk2gtd2gbf0: Rmdir: contains trashed file: "dmuvulfij81f693ur0f1vvbvq9v6iscp56daas3m51n9li5e3470" --- PASS: TestCopyMetadataNoEmptyDirs (7.10s) === RUN TestCopyMissingDirectory run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pefewaw2dupe'", Local "Local file system at /tmp/rclone22493455", Modify Window "1ms" 2025/03/11 07:25:08 DEBUG : Creating backend with remote "/non-existing" 2025/03/11 07:25:08 ERROR : Local file system at /non-existing: error reading source root directory: directory not found 2025/03/11 07:25:08 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pefewaw2dupe': Waiting for checks to finish 2025/03/11 07:25:08 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pefewaw2dupe': Waiting for transfers to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pefewaw2dupe'", Local "Local file system at /tmp/rclone22493455", Modify Window "1ms" --- PASS: TestCopyMissingDirectory (1.13s) === RUN TestCopyNoTraverse run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pefewaw2dupe'", Local "Local file system at /tmp/rclone22493455", Modify Window "1ms" 2025/03/11 07:25:09 DEBUG : Added delayed dir = "sub dir", newDst= 2025/03/11 07:25:09 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2025/03/11 07:25:09 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pefewaw2dupe': Waiting for checks to finish 2025/03/11 07:25:09 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pefewaw2dupe': Waiting for transfers to finish 2025/03/11 07:25:11 DEBUG : sub dir/hello world: md5 = d6fc6671504ac4a88f19befd73de18c9 OK 2025/03/11 07:25:11 INFO : sub dir/hello world: Copied (new) 2025/03/11 07:25:12 INFO : sub dir: Set directory modification time (using DirSetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pefewaw2dupe'", Local "Local file system at /tmp/rclone22493455", Modify Window "1ms" 2025/03/11 07:25:13 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestCopyNoTraverse (6.03s) === RUN TestCopyCheckFirst run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pefewaw2dupe'", Local "Local file system at /tmp/rclone22493455", Modify Window "1ms" 2025/03/11 07:25:15 INFO : Encrypted drive 'TestCryptDrive:rclone-test-pefewaw2dupe': Running all checks before starting transfers 2025/03/11 07:25:15 DEBUG : Added delayed dir = "sub dir", newDst= 2025/03/11 07:25:15 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2025/03/11 07:25:15 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pefewaw2dupe': Waiting for checks to finish 2025/03/11 07:25:15 INFO : Encrypted drive 'TestCryptDrive:rclone-test-pefewaw2dupe': Checks finished, now starting transfers 2025/03/11 07:25:15 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pefewaw2dupe': Waiting for transfers to finish 2025/03/11 07:25:17 DEBUG : sub dir/hello world: md5 = 75c8d2fb2eb7b6aa7c5506c5f4a89087 OK 2025/03/11 07:25:17 INFO : sub dir/hello world: Copied (new) 2025/03/11 07:25:18 INFO : sub dir: Set directory modification time (using DirSetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pefewaw2dupe'", Local "Local file system at /tmp/rclone22493455", Modify Window "1ms" 2025/03/11 07:25:20 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestCopyCheckFirst (6.29s) === RUN TestSyncNoTraverse run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pefewaw2dupe'", Local "Local file system at /tmp/rclone22493455", Modify Window "1ms" 2025/03/11 07:25:21 ERROR : Ignoring --no-traverse with sync 2025/03/11 07:25:21 DEBUG : Added delayed dir = "sub dir", newDst= 2025/03/11 07:25:21 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2025/03/11 07:25:21 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pefewaw2dupe': Waiting for checks to finish 2025/03/11 07:25:21 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pefewaw2dupe': Waiting for transfers to finish 2025/03/11 07:25:23 DEBUG : sub dir/hello world: md5 = 69a2134d7b064ab58181149c8b77bce1 OK 2025/03/11 07:25:23 INFO : sub dir/hello world: Copied (new) 2025/03/11 07:25:23 DEBUG : Waiting for deletions to finish 2025/03/11 07:25:24 INFO : sub dir: Set directory modification time (using DirSetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pefewaw2dupe'", Local "Local file system at /tmp/rclone22493455", Modify Window "1ms" 2025/03/11 07:25:26 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestSyncNoTraverse (5.72s) === RUN TestCopyWithDepth run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pefewaw2dupe'", Local "Local file system at /tmp/rclone22493455", Modify Window "1ms" 2025/03/11 07:25:27 DEBUG : hello world2: Need to transfer - File not found at Destination 2025/03/11 07:25:27 DEBUG : Added delayed dir = "sub dir", newDst= 2025/03/11 07:25:27 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pefewaw2dupe': Waiting for checks to finish 2025/03/11 07:25:27 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pefewaw2dupe': Waiting for transfers to finish 2025/03/11 07:25:28 DEBUG : hello world2: md5 = 9f90b0fedb8c960c1c79b220f451845e OK 2025/03/11 07:25:28 INFO : hello world2: Copied (new) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pefewaw2dupe'", Local "Local file system at /tmp/rclone22493455", Modify Window "1ms" --- PASS: TestCopyWithDepth (3.24s) === RUN TestCopyWithFilesFrom run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pefewaw2dupe'", Local "Local file system at /tmp/rclone22493455", Modify Window "1ms" 2025/03/11 07:25:30 DEBUG : potato2: Need to transfer - File not found at Destination 2025/03/11 07:25:30 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pefewaw2dupe': Waiting for checks to finish 2025/03/11 07:25:30 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pefewaw2dupe': Waiting for transfers to finish 2025/03/11 07:25:32 DEBUG : potato2: md5 = 0715a5b84606d713b3c1b22e973a7f8d OK 2025/03/11 07:25:32 INFO : potato2: Copied (new) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pefewaw2dupe'", Local "Local file system at /tmp/rclone22493455", Modify Window "1ms" --- PASS: TestCopyWithFilesFrom (3.29s) === RUN TestCopyWithFilesFromAndNoTraverse run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pefewaw2dupe'", Local "Local file system at /tmp/rclone22493455", Modify Window "1ms" 2025/03/11 07:25:33 DEBUG : potato2: Need to transfer - File not found at Destination 2025/03/11 07:25:33 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pefewaw2dupe': Waiting for checks to finish 2025/03/11 07:25:33 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pefewaw2dupe': Waiting for transfers to finish 2025/03/11 07:25:35 DEBUG : potato2: md5 = 100a03819257799151e815bfeb2603bf OK 2025/03/11 07:25:35 INFO : potato2: Copied (new) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pefewaw2dupe'", Local "Local file system at /tmp/rclone22493455", Modify Window "1ms" --- PASS: TestCopyWithFilesFromAndNoTraverse (3.32s) === RUN TestCopyEmptyDirectories run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pefewaw2dupe'", Local "Local file system at /tmp/rclone22493455", Modify Window "1ms" 2025/03/11 07:25:37 DEBUG : sub dir2/sub sub dir2: Making directory with metadata 2025/03/11 07:25:37 INFO : sub dir2/sub sub dir2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2025/03/11 07:25:37 INFO : sub dir2: Set directory modification time (using DirSetModTime) 2025/03/11 07:25:37 INFO : sub dir: Set directory modification time (using DirSetModTime) 2025/03/11 07:25:37 DEBUG : sub dir: Making directory with metadata 2025/03/11 07:25:38 INFO : sub dir: Made directory with metadata (mtime=2001-02-03T04:05:06.499999999Z) 2025/03/11 07:25:38 DEBUG : sub dir2: Making directory with metadata 2025/03/11 07:25:38 INFO : sub dir2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2025/03/11 07:25:38 DEBUG : sub dir2/sub sub dir2: Making directory with metadata 2025/03/11 07:25:38 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2025/03/11 07:25:39 INFO : sub dir2/sub sub dir2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2025/03/11 07:25:39 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pefewaw2dupe': Waiting for checks to finish 2025/03/11 07:25:39 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pefewaw2dupe': Waiting for transfers to finish 2025/03/11 07:25:40 DEBUG : sub dir/hello world: md5 = a4286f8e83d456b839c6c2da78dc57cd OK 2025/03/11 07:25:40 INFO : sub dir/hello world: Copied (new) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pefewaw2dupe'", Local "Local file system at /tmp/rclone22493455", Modify Window "1ms" 2025/03/11 07:25:44 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc: Rmdir: contains trashed file: "cv6a9uf28ngrajena8kt5ijjn0" 2025/03/11 07:25:45 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestCopyEmptyDirectories (9.30s) === RUN TestCopyNoEmptyDirectories run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pefewaw2dupe'", Local "Local file system at /tmp/rclone22493455", Modify Window "1ms" 2025/03/11 07:25:46 INFO : sub dir2: Making directory 2025/03/11 07:25:46 DEBUG : sub dir2/sub sub dir2: Making directory with metadata 2025/03/11 07:25:46 INFO : sub dir2/sub sub dir2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2025/03/11 07:25:46 DEBUG : Added delayed dir = "sub dir", newDst= 2025/03/11 07:25:46 DEBUG : Added delayed dir = "sub dir2", newDst= 2025/03/11 07:25:46 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2025/03/11 07:25:46 DEBUG : Added delayed dir = "sub dir2/sub sub dir2", newDst= 2025/03/11 07:25:46 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pefewaw2dupe': Waiting for checks to finish 2025/03/11 07:25:46 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pefewaw2dupe': Waiting for transfers to finish 2025/03/11 07:25:48 DEBUG : sub dir/hello world: md5 = fa019da025e6b094276303ad79051201 OK 2025/03/11 07:25:48 INFO : sub dir/hello world: Copied (new) 2025/03/11 07:25:49 INFO : sub dir: Set directory modification time (using DirSetModTime) 2025/03/11 07:25:51 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestCopyNoEmptyDirectories (5.63s) === RUN TestMoveEmptyDirectories run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pefewaw2dupe'", Local "Local file system at /tmp/rclone22493455", Modify Window "1ms" 2025/03/11 07:25:51 DEBUG : sub dir2: Making directory with metadata 2025/03/11 07:25:51 INFO : sub dir2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2025/03/11 07:25:52 DEBUG : sub dir: Making directory with metadata 2025/03/11 07:25:52 INFO : sub dir: Made directory with metadata (mtime=2025-03-11T07:25:51.965704991Z) 2025/03/11 07:25:52 DEBUG : sub dir2: Making directory with metadata 2025/03/11 07:25:53 INFO : sub dir2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2025/03/11 07:25:53 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2025/03/11 07:25:53 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pefewaw2dupe': Waiting for checks to finish 2025/03/11 07:25:53 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pefewaw2dupe': Waiting for transfers to finish 2025/03/11 07:25:55 DEBUG : sub dir/hello world: md5 = a63bce7892284dd9fa8ad04d4c69987b OK 2025/03/11 07:25:55 INFO : sub dir/hello world: Copied (new) 2025/03/11 07:25:55 INFO : sub dir/hello world: Deleted run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pefewaw2dupe'", Local "Local file system at /tmp/rclone22493455", Modify Window "1ms" 2025/03/11 07:25:58 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestMoveEmptyDirectories (7.20s) === RUN TestSyncNoUpdateDirModtime run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pefewaw2dupe'", Local "Local file system at /tmp/rclone22493455", Modify Window "1ms" 2025/03/11 07:25:59 DEBUG : sub dir no update dir modtime: Making directory with metadata 2025/03/11 07:25:59 INFO : sub dir no update dir modtime: Made directory with metadata (mtime=2001-02-03T04:05:06.499999999Z) 2025/03/11 07:26:00 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pefewaw2dupe': Waiting for checks to finish 2025/03/11 07:26:00 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pefewaw2dupe': Waiting for transfers to finish 2025/03/11 07:26:00 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pefewaw2dupe'", Local "Local file system at /tmp/rclone22493455", Modify Window "1ms" --- PASS: TestSyncNoUpdateDirModtime (4.07s) === RUN TestMoveNoEmptyDirectories run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pefewaw2dupe'", Local "Local file system at /tmp/rclone22493455", Modify Window "1ms" 2025/03/11 07:26:03 INFO : sub dir2: Making directory 2025/03/11 07:26:03 DEBUG : Added delayed dir = "sub dir", newDst= 2025/03/11 07:26:03 DEBUG : Added delayed dir = "sub dir2", newDst= 2025/03/11 07:26:03 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2025/03/11 07:26:03 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pefewaw2dupe': Waiting for checks to finish 2025/03/11 07:26:03 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pefewaw2dupe': Waiting for transfers to finish 2025/03/11 07:26:05 DEBUG : sub dir/hello world: md5 = fba29440c7c3b2ec7fe164f31cbb446d OK 2025/03/11 07:26:05 INFO : sub dir/hello world: Copied (new) 2025/03/11 07:26:05 INFO : sub dir/hello world: Deleted 2025/03/11 07:26:06 INFO : sub dir: Set directory modification time (using DirSetModTime) 2025/03/11 07:26:07 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestMoveNoEmptyDirectories (5.37s) === RUN TestSyncEmptyDirectories run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pefewaw2dupe'", Local "Local file system at /tmp/rclone22493455", Modify Window "1ms" 2025/03/11 07:26:08 DEBUG : sub dir2: Making directory with metadata 2025/03/11 07:26:08 INFO : sub dir2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2025/03/11 07:26:08 INFO : sub dir: Set directory modification time (using DirSetModTime) 2025/03/11 07:26:08 DEBUG : sub dir: Making directory with metadata 2025/03/11 07:26:09 INFO : sub dir: Made directory with metadata (mtime=2001-02-03T04:05:06.499999999Z) 2025/03/11 07:26:09 DEBUG : sub dir2: Making directory with metadata 2025/03/11 07:26:10 INFO : sub dir2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2025/03/11 07:26:10 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2025/03/11 07:26:10 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pefewaw2dupe': Waiting for checks to finish 2025/03/11 07:26:10 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pefewaw2dupe': Waiting for transfers to finish 2025/03/11 07:26:11 DEBUG : sub dir/hello world: md5 = 925f9d43c69eb78b589bfbc97c334318 OK 2025/03/11 07:26:11 INFO : sub dir/hello world: Copied (new) 2025/03/11 07:26:11 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pefewaw2dupe'", Local "Local file system at /tmp/rclone22493455", Modify Window "1ms" 2025/03/11 07:26:14 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestSyncEmptyDirectories (7.43s) === RUN TestSyncSetDelayedModTimes run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pefewaw2dupe'", Local "Local file system at /tmp/rclone22493455", Modify Window "1ms" sync_test.go:507: Backend doesn't have DirModTimeUpdatesOnWrite set --- SKIP: TestSyncSetDelayedModTimes (0.43s) === RUN TestSyncNoEmptyDirectories run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pefewaw2dupe'", Local "Local file system at /tmp/rclone22493455", Modify Window "1ms" 2025/03/11 07:26:16 INFO : sub dir2: Making directory 2025/03/11 07:26:16 DEBUG : Added delayed dir = "sub dir", newDst= 2025/03/11 07:26:16 DEBUG : Added delayed dir = "sub dir2", newDst= 2025/03/11 07:26:16 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2025/03/11 07:26:16 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pefewaw2dupe': Waiting for checks to finish 2025/03/11 07:26:16 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pefewaw2dupe': Waiting for transfers to finish 2025/03/11 07:26:18 DEBUG : sub dir/hello world: md5 = a23b0eb2c0ac4b376f56c91c097fa573 OK 2025/03/11 07:26:18 INFO : sub dir/hello world: Copied (new) 2025/03/11 07:26:18 DEBUG : Waiting for deletions to finish 2025/03/11 07:26:19 INFO : sub dir: Set directory modification time (using DirSetModTime) 2025/03/11 07:26:21 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestSyncNoEmptyDirectories (5.41s) === RUN TestServerSideCopy run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pefewaw2dupe'", Local "Local file system at /tmp/rclone22493455", Modify Window "1ms" 2025/03/11 07:26:23 DEBUG : sub dir/hello world: md5 = 62b282c1bf51abe3589fa2ba97108f58 OK 2025/03/11 07:26:24 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-gokalih3mole" 2025/03/11 07:26:24 DEBUG : Config file has changed externally - reloading 2025/03/11 07:26:24 DEBUG : Creating backend with remote "TestDrive:crypt/v0i9mh3i9iqe89hrs4jpms150o75idvsaia19m71osfup6gr8ca0" sync_test.go:590: Server side copy (if possible) Encrypted drive 'TestCryptDrive:rclone-test-pefewaw2dupe' -> Encrypted drive 'TestCryptDrive:rclone-test-gokalih3mole' 2025/03/11 07:26:26 DEBUG : Added delayed dir = "sub dir", newDst= 2025/03/11 07:26:26 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2025/03/11 07:26:26 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gokalih3mole': Waiting for checks to finish 2025/03/11 07:26:26 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gokalih3mole': Waiting for transfers to finish 2025/03/11 07:26:28 INFO : sub dir/hello world: Copied (server-side copy) 2025/03/11 07:26:29 INFO : sub dir: Set directory modification time (using DirSetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pefewaw2dupe'", Local "Local file system at /tmp/rclone22493455", Modify Window "1ms" 2025/03/11 07:26:29 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gokalih3mole': Purge remote 2025/03/11 07:26:31 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestServerSideCopy (10.79s) === RUN TestCopyOverSelf run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pefewaw2dupe'", Local "Local file system at /tmp/rclone22493455", Modify Window "1ms" 2025/03/11 07:26:35 DEBUG : sub dir/hello world: md5 = 4377d47ce0fdc0bdefe3901468cae4bb OK 2025/03/11 07:26:36 INFO : sub dir: Set directory modification time (using SetModTime) 2025/03/11 07:26:36 DEBUG : Added delayed dir = "sub dir", newDst=sub dir 2025/03/11 07:26:36 DEBUG : sub dir/hello world: Sizes differ (src 17 vs dst 11) 2025/03/11 07:26:36 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pefewaw2dupe': Waiting for checks to finish 2025/03/11 07:26:36 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pefewaw2dupe': Waiting for transfers to finish 2025/03/11 07:26:37 DEBUG : sub dir/hello world: md5 = e4c4b34b888ece555c364f7d31406efb OK 2025/03/11 07:26:37 INFO : sub dir/hello world: Copied (replaced existing) 2025/03/11 07:26:38 INFO : sub dir: Set directory modification time (using SetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pefewaw2dupe'", Local "Local file system at /tmp/rclone22493455", Modify Window "1ms" 2025/03/11 07:26:40 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestCopyOverSelf (9.09s) === RUN TestServerSideCopyOverSelf run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pefewaw2dupe'", Local "Local file system at /tmp/rclone22493455", Modify Window "1ms" 2025/03/11 07:26:44 DEBUG : sub dir/hello world: md5 = 901fa90bc9627c67a9c3da115cbfc456 OK 2025/03/11 07:26:44 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-leloxet3havu" 2025/03/11 07:26:44 DEBUG : Creating backend with remote "TestDrive:crypt/5442oq0dubi45erd01sjgqguoisl6rqng3nvq4ck2c0d8i6pr7kg" sync_test.go:626: Server side copy (if possible) Encrypted drive 'TestCryptDrive:rclone-test-pefewaw2dupe' -> Encrypted drive 'TestCryptDrive:rclone-test-leloxet3havu' 2025/03/11 07:26:46 DEBUG : Added delayed dir = "sub dir", newDst= 2025/03/11 07:26:46 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2025/03/11 07:26:46 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-leloxet3havu': Waiting for checks to finish 2025/03/11 07:26:46 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-leloxet3havu': Waiting for transfers to finish 2025/03/11 07:26:48 INFO : sub dir/hello world: Copied (server-side copy) 2025/03/11 07:26:48 INFO : sub dir: Set directory modification time (using DirSetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pefewaw2dupe'", Local "Local file system at /tmp/rclone22493455", Modify Window "1ms" 2025/03/11 07:26:50 DEBUG : sub dir/hello world: md5 = fb437425590e05a556e114376338b140 OK 2025/03/11 07:26:51 DEBUG : sub dir: Directory modification time the same (differ by 0s, within tolerance 1ms) 2025/03/11 07:26:51 DEBUG : Added delayed dir = "sub dir", newDst=sub dir 2025/03/11 07:26:51 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-leloxet3havu': Waiting for checks to finish 2025/03/11 07:26:51 DEBUG : sub dir/hello world: Sizes differ (src 17 vs dst 11) 2025/03/11 07:26:51 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-leloxet3havu': Waiting for transfers to finish 2025/03/11 07:26:53 INFO : sub dir/hello world: Copied (server-side copy) 2025/03/11 07:26:53 INFO : sub dir: Set directory modification time (using SetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pefewaw2dupe'", Local "Local file system at /tmp/rclone22493455", Modify Window "1ms" 2025/03/11 07:26:54 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-leloxet3havu': Purge remote 2025/03/11 07:26:55 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestServerSideCopyOverSelf (15.94s) === RUN TestMoveOverSelf run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pefewaw2dupe'", Local "Local file system at /tmp/rclone22493455", Modify Window "1ms" 2025/03/11 07:26:59 DEBUG : sub dir/hello world: md5 = 52ad5380f8a859d60c9c676efaf524a4 OK 2025/03/11 07:27:01 INFO : sub dir: Set directory modification time (using SetModTime) 2025/03/11 07:27:01 DEBUG : Added delayed dir = "sub dir", newDst=sub dir 2025/03/11 07:27:01 DEBUG : sub dir/hello world: Sizes differ (src 17 vs dst 11) 2025/03/11 07:27:01 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pefewaw2dupe': Waiting for checks to finish 2025/03/11 07:27:01 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pefewaw2dupe': Waiting for transfers to finish 2025/03/11 07:27:02 DEBUG : sub dir/hello world: md5 = c59ce259909b434fcdfe653562a96175 OK 2025/03/11 07:27:02 INFO : sub dir/hello world: Copied (replaced existing) 2025/03/11 07:27:02 INFO : sub dir/hello world: Deleted 2025/03/11 07:27:03 INFO : sub dir: Set directory modification time (using SetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pefewaw2dupe'", Local "Local file system at /tmp/rclone22493455", Modify Window "1ms" 2025/03/11 07:27:04 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestMoveOverSelf (8.16s) === RUN TestServerSideMoveOverSelf run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pefewaw2dupe'", Local "Local file system at /tmp/rclone22493455", Modify Window "1ms" 2025/03/11 07:27:08 DEBUG : sub dir/hello world: md5 = a0fb705841147efc1ae5c4ae1a7a1f22 OK 2025/03/11 07:27:08 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-xacukuz2kogi" 2025/03/11 07:27:08 DEBUG : Creating backend with remote "TestDrive:crypt/e4tqff5eqq363i7q2rijfunn7lce2jnrdfpb31ukr3gbipogu0kg" sync_test.go:671: Server side copy (if possible) Encrypted drive 'TestCryptDrive:rclone-test-pefewaw2dupe' -> Encrypted drive 'TestCryptDrive:rclone-test-xacukuz2kogi' 2025/03/11 07:27:10 DEBUG : Added delayed dir = "sub dir", newDst= 2025/03/11 07:27:10 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2025/03/11 07:27:10 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-xacukuz2kogi': Waiting for checks to finish 2025/03/11 07:27:10 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-xacukuz2kogi': Waiting for transfers to finish 2025/03/11 07:27:12 INFO : sub dir/hello world: Copied (server-side copy) 2025/03/11 07:27:13 INFO : sub dir: Set directory modification time (using DirSetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pefewaw2dupe'", Local "Local file system at /tmp/rclone22493455", Modify Window "1ms" 2025/03/11 07:27:15 DEBUG : sub dir/hello world: md5 = b5263e819e32e44f15bf373d67da5f0d OK 2025/03/11 07:27:15 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-xacukuz2kogi': Using server-side directory move 2025/03/11 07:27:15 INFO : Encrypted drive 'TestCryptDrive:rclone-test-xacukuz2kogi': Server side directory move failed - fallback to file moves: can't copy directory - destination already exists 2025/03/11 07:27:16 DEBUG : sub dir: Directory modification time the same (differ by 0s, within tolerance 1ms) 2025/03/11 07:27:16 DEBUG : Added delayed dir = "sub dir", newDst=sub dir 2025/03/11 07:27:16 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-xacukuz2kogi': Waiting for checks to finish 2025/03/11 07:27:16 DEBUG : sub dir/hello world: Sizes differ (src 17 vs dst 11) 2025/03/11 07:27:16 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-xacukuz2kogi': Waiting for transfers to finish 2025/03/11 07:27:16 INFO : sub dir/hello world: Deleted 2025/03/11 07:27:17 INFO : sub dir/hello world: Moved (server-side) 2025/03/11 07:27:17 INFO : sub dir: Set directory modification time (using SetModTime) 2025/03/11 07:27:21 DEBUG : sub dir/hello world: md5 = 61da125bf22ef29a4450015081a9f838 OK 2025/03/11 07:27:22 DEBUG : testing file moves 2025/03/11 07:27:22 DEBUG : sub dir: Directory modification time the same (differ by 0s, within tolerance 1ms) 2025/03/11 07:27:22 DEBUG : Added delayed dir = "sub dir", newDst=sub dir 2025/03/11 07:27:22 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-xacukuz2kogi': Waiting for checks to finish 2025/03/11 07:27:22 DEBUG : sub dir/hello world: Sizes differ (src 24 vs dst 17) 2025/03/11 07:27:22 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-xacukuz2kogi': Waiting for transfers to finish 2025/03/11 07:27:23 INFO : sub dir/hello world: Deleted 2025/03/11 07:27:23 INFO : sub dir/hello world: Moved (server-side) 2025/03/11 07:27:24 INFO : sub dir: Set directory modification time (using SetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pefewaw2dupe'", Local "Local file system at /tmp/rclone22493455", Modify Window "1ms" 2025/03/11 07:27:25 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-xacukuz2kogi': Purge remote --- PASS: TestServerSideMoveOverSelf (22.26s) === RUN TestCopyAfterDelete run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pefewaw2dupe'", Local "Local file system at /tmp/rclone22493455", Modify Window "1ms" 2025/03/11 07:27:30 DEBUG : sub dir/hello world: md5 = 1d15a85114496ed364fdf74687ef1f47 OK 2025/03/11 07:27:30 ERROR : : error listing: directory not found 2025/03/11 07:27:30 INFO : Local file system at /tmp/rclone22493455: Making directory 2025/03/11 07:27:31 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pefewaw2dupe': Waiting for checks to finish 2025/03/11 07:27:31 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pefewaw2dupe': Waiting for transfers to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pefewaw2dupe'", Local "Local file system at /tmp/rclone22493455", Modify Window "1ms" 2025/03/11 07:27:33 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestCopyAfterDelete (6.26s) === RUN TestCopyRedownload run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pefewaw2dupe'", Local "Local file system at /tmp/rclone22493455", Modify Window "1ms" 2025/03/11 07:27:36 DEBUG : sub dir/hello world: md5 = 184b28cb1163834c0aca51f9f85214da OK 2025/03/11 07:27:37 DEBUG : Added delayed dir = "sub dir", newDst= 2025/03/11 07:27:37 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2025/03/11 07:27:37 DEBUG : Local file system at /tmp/rclone22493455: Waiting for checks to finish 2025/03/11 07:27:37 DEBUG : Local file system at /tmp/rclone22493455: Waiting for transfers to finish 2025/03/11 07:27:38 DEBUG : sub dir/hello world.285f0a30.partial: renamed to: sub dir/hello world 2025/03/11 07:27:38 INFO : sub dir/hello world: Copied (new) 2025/03/11 07:27:38 INFO : sub dir: Set directory modification time (using DirSetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pefewaw2dupe'", Local "Local file system at /tmp/rclone22493455", Modify Window "1ms" 2025/03/11 07:27:39 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestCopyRedownload (6.65s) === RUN TestSyncBasedOnCheckSum run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pefewaw2dupe'", Local "Local file system at /tmp/rclone22493455", Modify Window "1ms" 2025/03/11 07:27:41 DEBUG : check sum: Need to transfer - File not found at Destination 2025/03/11 07:27:41 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pefewaw2dupe': Waiting for checks to finish 2025/03/11 07:27:41 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pefewaw2dupe': Waiting for transfers to finish 2025/03/11 07:27:42 DEBUG : check sum: md5 = 18356b235ec61724c58055538281fa60 OK 2025/03/11 07:27:42 INFO : check sum: Copied (new) 2025/03/11 07:27:42 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pefewaw2dupe'", Local "Local file system at /tmp/rclone22493455", Modify Window "1ms" 2025/03/11 07:27:43 NOTICE: Encrypted drive 'TestCryptDrive:rclone-test-pefewaw2dupe': --checksum is in use but the source and destination have no hashes in common; falling back to --size-only 2025/03/11 07:27:43 DEBUG : check sum: Size of src and dst objects identical 2025/03/11 07:27:43 DEBUG : check sum: Unchanged skipping 2025/03/11 07:27:43 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pefewaw2dupe': Waiting for checks to finish 2025/03/11 07:27:43 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pefewaw2dupe': Waiting for transfers to finish 2025/03/11 07:27:43 DEBUG : Waiting for deletions to finish 2025/03/11 07:27:43 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pefewaw2dupe'", Local "Local file system at /tmp/rclone22493455", Modify Window "1ms" --- PASS: TestSyncBasedOnCheckSum (4.32s) === RUN TestSyncSizeOnly run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pefewaw2dupe'", Local "Local file system at /tmp/rclone22493455", Modify Window "1ms" 2025/03/11 07:27:45 DEBUG : sizeonly: Need to transfer - File not found at Destination 2025/03/11 07:27:45 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pefewaw2dupe': Waiting for checks to finish 2025/03/11 07:27:45 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pefewaw2dupe': Waiting for transfers to finish 2025/03/11 07:27:46 DEBUG : sizeonly: md5 = fb09f77cff6824568f9b67bd325d4654 OK 2025/03/11 07:27:46 INFO : sizeonly: Copied (new) 2025/03/11 07:27:46 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pefewaw2dupe'", Local "Local file system at /tmp/rclone22493455", Modify Window "1ms" 2025/03/11 07:27:47 DEBUG : sizeonly: Sizes identical 2025/03/11 07:27:47 DEBUG : sizeonly: Unchanged skipping 2025/03/11 07:27:47 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pefewaw2dupe': Waiting for checks to finish 2025/03/11 07:27:47 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pefewaw2dupe': Waiting for transfers to finish 2025/03/11 07:27:47 DEBUG : Waiting for deletions to finish 2025/03/11 07:27:47 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pefewaw2dupe'", Local "Local file system at /tmp/rclone22493455", Modify Window "1ms" --- PASS: TestSyncSizeOnly (4.52s) === RUN TestSyncIgnoreSize run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pefewaw2dupe'", Local "Local file system at /tmp/rclone22493455", Modify Window "1ms" 2025/03/11 07:27:50 DEBUG : ignore-size: Need to transfer - File not found at Destination 2025/03/11 07:27:50 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pefewaw2dupe': Waiting for checks to finish 2025/03/11 07:27:50 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pefewaw2dupe': Waiting for transfers to finish 2025/03/11 07:27:51 DEBUG : ignore-size: md5 = 1edf08f8ba8588f197cc969ba9d3c0ac OK 2025/03/11 07:27:51 INFO : ignore-size: Copied (new) 2025/03/11 07:27:51 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pefewaw2dupe'", Local "Local file system at /tmp/rclone22493455", Modify Window "1ms" 2025/03/11 07:27:52 DEBUG : ignore-size: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/03/11 07:27:52 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pefewaw2dupe': Waiting for checks to finish 2025/03/11 07:27:52 DEBUG : ignore-size: Unchanged skipping 2025/03/11 07:27:52 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pefewaw2dupe': Waiting for transfers to finish 2025/03/11 07:27:52 DEBUG : Waiting for deletions to finish 2025/03/11 07:27:52 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pefewaw2dupe'", Local "Local file system at /tmp/rclone22493455", Modify Window "1ms" --- PASS: TestSyncIgnoreSize (4.48s) === RUN TestSyncIgnoreTimes run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pefewaw2dupe'", Local "Local file system at /tmp/rclone22493455", Modify Window "1ms" 2025/03/11 07:27:55 DEBUG : existing: md5 = 98e6105092ad4ec7be12e50be571928e OK 2025/03/11 07:27:56 DEBUG : existing: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/03/11 07:27:56 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pefewaw2dupe': Waiting for checks to finish 2025/03/11 07:27:56 DEBUG : existing: Unchanged skipping 2025/03/11 07:27:56 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pefewaw2dupe': Waiting for transfers to finish 2025/03/11 07:27:56 DEBUG : Waiting for deletions to finish 2025/03/11 07:27:56 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pefewaw2dupe'", Local "Local file system at /tmp/rclone22493455", Modify Window "1ms" 2025/03/11 07:27:56 DEBUG : existing: Transferring unconditionally as --ignore-times is in use 2025/03/11 07:27:56 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pefewaw2dupe': Waiting for checks to finish 2025/03/11 07:27:56 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pefewaw2dupe': Waiting for transfers to finish 2025/03/11 07:27:57 DEBUG : existing: md5 = 1f49acf99a4703bb9668b47876a8765d OK 2025/03/11 07:27:57 INFO : existing: Copied (replaced existing) 2025/03/11 07:27:57 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pefewaw2dupe'", Local "Local file system at /tmp/rclone22493455", Modify Window "1ms" --- PASS: TestSyncIgnoreTimes (5.69s) === RUN TestSyncIgnoreExisting run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pefewaw2dupe'", Local "Local file system at /tmp/rclone22493455", Modify Window "1ms" 2025/03/11 07:28:00 DEBUG : existing: Need to transfer - File not found at Destination 2025/03/11 07:28:00 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pefewaw2dupe': Waiting for checks to finish 2025/03/11 07:28:00 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pefewaw2dupe': Waiting for transfers to finish 2025/03/11 07:28:01 DEBUG : existing: md5 = 9f1c98f4694d70a42bdc98197258dfd6 OK 2025/03/11 07:28:01 INFO : existing: Copied (new) 2025/03/11 07:28:01 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pefewaw2dupe'", Local "Local file system at /tmp/rclone22493455", Modify Window "1ms" 2025/03/11 07:28:02 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pefewaw2dupe': Waiting for checks to finish 2025/03/11 07:28:02 DEBUG : existing: Destination exists, skipping 2025/03/11 07:28:02 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pefewaw2dupe': Waiting for transfers to finish 2025/03/11 07:28:02 DEBUG : Waiting for deletions to finish 2025/03/11 07:28:02 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pefewaw2dupe'", Local "Local file system at /tmp/rclone22493455", Modify Window "1ms" --- PASS: TestSyncIgnoreExisting (4.20s) === RUN TestSyncIgnoreErrors run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pefewaw2dupe'", Local "Local file system at /tmp/rclone22493455", Modify Window "1ms" 2025/03/11 07:28:06 DEBUG : b/potato: md5 = f1e221438d3e258a2cabde23b412e091 OK 2025/03/11 07:28:08 DEBUG : c/non empty space: md5 = 39b61f58204e112d71c0a5b0b76f3f7e OK 2025/03/11 07:28:08 INFO : d: Making directory 2025/03/11 07:28:10 DEBUG : Added delayed dir = "a", newDst= 2025/03/11 07:28:10 INFO : c: Set directory modification time (using SetModTime) 2025/03/11 07:28:10 DEBUG : Added delayed dir = "c", newDst=c 2025/03/11 07:28:10 DEBUG : c/non empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/03/11 07:28:10 DEBUG : a/potato2: Need to transfer - File not found at Destination 2025/03/11 07:28:10 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pefewaw2dupe': Waiting for checks to finish 2025/03/11 07:28:10 DEBUG : c/non empty space: Unchanged skipping 2025/03/11 07:28:10 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pefewaw2dupe': Waiting for transfers to finish 2025/03/11 07:28:12 DEBUG : a/potato2: md5 = dad61186ec9a9c0397f7509c146a63ae OK 2025/03/11 07:28:12 INFO : a/potato2: Copied (new) 2025/03/11 07:28:12 DEBUG : Waiting for deletions to finish 2025/03/11 07:28:13 INFO : b/potato: Deleted 2025/03/11 07:28:13 INFO : a: Set directory modification time (using DirSetModTime) 2025/03/11 07:28:13 INFO : d: Removing directory 2025/03/11 07:28:14 INFO : b: Removing directory 2025/03/11 07:28:14 DEBUG : 32d8ua6196mc1r7qkfog53rkg0: Rmdir: contains trashed file: "2m507n64kafsi59v9q71r281a4" 2025/03/11 07:28:15 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pefewaw2dupe': deleted 2 directories run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pefewaw2dupe'", Local "Local file system at /tmp/rclone22493455", Modify Window "1ms" 2025/03/11 07:28:17 DEBUG : 3i9du405pfogq3ncai6pg7ouio: Rmdir: contains trashed file: "982d3pss7t5pn0il16r2foj31s" 2025/03/11 07:28:18 DEBUG : 2bsvlrk2ne1lfitm6tttcu0qt8: Rmdir: contains trashed file: "89l8renevh3mji1c8r1p7qn6tg" --- PASS: TestSyncIgnoreErrors (15.30s) === RUN TestSyncAfterChangingModtimeOnly run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pefewaw2dupe'", Local "Local file system at /tmp/rclone22493455", Modify Window "1ms" 2025/03/11 07:28:20 DEBUG : empty space: md5 = 7010dd360807ab3df869e7dd4829bda4 OK 2025/03/11 07:28:21 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/11 07:28:21 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pefewaw2dupe': Waiting for checks to finish 2025/03/11 07:28:21 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pefewaw2dupe': Waiting for transfers to finish 2025/03/11 07:28:21 NOTICE: empty space: Skipped copy as --dry-run is set (size 1) 2025/03/11 07:28:21 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pefewaw2dupe'", Local "Local file system at /tmp/rclone22493455", Modify Window "1ms" 2025/03/11 07:28:21 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pefewaw2dupe': Waiting for checks to finish 2025/03/11 07:28:21 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/11 07:28:21 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pefewaw2dupe': Waiting for transfers to finish 2025/03/11 07:28:23 DEBUG : empty space: md5 = 135fa9f5a32464784e60a104d233a0bb OK 2025/03/11 07:28:23 INFO : empty space: Copied (replaced existing) 2025/03/11 07:28:23 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pefewaw2dupe'", Local "Local file system at /tmp/rclone22493455", Modify Window "1ms" --- PASS: TestSyncAfterChangingModtimeOnly (5.60s) === RUN TestSyncAfterChangingModtimeOnlyWithNoUpdateModTime run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pefewaw2dupe'", Local "Local file system at /tmp/rclone22493455", Modify Window "1ms" sync_test.go:1016: Can't check this if no hashes supported --- PASS: TestSyncAfterChangingModtimeOnlyWithNoUpdateModTime (0.46s) === RUN TestSyncDoesntUpdateModtime run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pefewaw2dupe'", Local "Local file system at /tmp/rclone22493455", Modify Window "1ms" 2025/03/11 07:28:26 DEBUG : foo: md5 = c315997a191c5f1d7f71f54453408a7d OK 2025/03/11 07:28:27 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pefewaw2dupe': Waiting for checks to finish 2025/03/11 07:28:27 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/11 07:28:27 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pefewaw2dupe': Waiting for transfers to finish 2025/03/11 07:28:28 DEBUG : foo: md5 = 3a90a2ce1cefd36c2191f2028ea5356f OK 2025/03/11 07:28:28 INFO : foo: Copied (replaced existing) 2025/03/11 07:28:28 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pefewaw2dupe'", Local "Local file system at /tmp/rclone22493455", Modify Window "1ms" --- PASS: TestSyncDoesntUpdateModtime (4.73s) === RUN TestSyncAfterAddingAFile run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pefewaw2dupe'", Local "Local file system at /tmp/rclone22493455", Modify Window "1ms" 2025/03/11 07:28:31 DEBUG : empty space: md5 = 3545f75fc349abfccfd41b22308b4339 OK 2025/03/11 07:28:32 DEBUG : potato: Need to transfer - File not found at Destination 2025/03/11 07:28:32 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pefewaw2dupe': Waiting for checks to finish 2025/03/11 07:28:32 DEBUG : empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/03/11 07:28:32 DEBUG : empty space: Unchanged skipping 2025/03/11 07:28:32 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pefewaw2dupe': Waiting for transfers to finish 2025/03/11 07:28:33 DEBUG : potato: md5 = 72e628be0ede64c06c6871d039e8ebe2 OK 2025/03/11 07:28:33 INFO : potato: Copied (new) 2025/03/11 07:28:33 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pefewaw2dupe'", Local "Local file system at /tmp/rclone22493455", Modify Window "1ms" --- PASS: TestSyncAfterAddingAFile (5.23s) === RUN TestSyncAfterChangingFilesSizeOnly run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pefewaw2dupe'", Local "Local file system at /tmp/rclone22493455", Modify Window "1ms" 2025/03/11 07:28:36 DEBUG : potato: md5 = b906dc431dd5ccf53ed2abc4775cfae2 OK 2025/03/11 07:28:37 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pefewaw2dupe': Waiting for checks to finish 2025/03/11 07:28:37 DEBUG : potato: Sizes differ (src 21 vs dst 60) 2025/03/11 07:28:37 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pefewaw2dupe': Waiting for transfers to finish 2025/03/11 07:28:38 DEBUG : potato: md5 = 06a5c59d0a55cc6a6ffea2bdd3b2a789 OK 2025/03/11 07:28:38 INFO : potato: Copied (replaced existing) 2025/03/11 07:28:38 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pefewaw2dupe'", Local "Local file system at /tmp/rclone22493455", Modify Window "1ms" --- PASS: TestSyncAfterChangingFilesSizeOnly (4.67s) === RUN TestSyncAfterChangingContentsOnly run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pefewaw2dupe'", Local "Local file system at /tmp/rclone22493455", Modify Window "1ms" 2025/03/11 07:28:41 DEBUG : potato: md5 = f8be4f97418519ca5c9a955659feb0a4 OK 2025/03/11 07:28:42 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pefewaw2dupe': Waiting for checks to finish 2025/03/11 07:28:42 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/11 07:28:42 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pefewaw2dupe': Waiting for transfers to finish 2025/03/11 07:28:43 DEBUG : potato: md5 = 9eac1e8f65b0e9c9ffb995293784af0a OK 2025/03/11 07:28:43 INFO : potato: Copied (replaced existing) 2025/03/11 07:28:43 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pefewaw2dupe'", Local "Local file system at /tmp/rclone22493455", Modify Window "1ms" --- PASS: TestSyncAfterChangingContentsOnly (5.09s) === RUN TestSyncAfterRemovingAFileAndAddingAFileDryRun run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pefewaw2dupe'", Local "Local file system at /tmp/rclone22493455", Modify Window "1ms" 2025/03/11 07:28:46 DEBUG : potato: md5 = 0876aee5d4e92f2585ef648801e43dad OK 2025/03/11 07:28:48 DEBUG : empty space: md5 = 64650fc59b5a3506ac3c87c5aeb7d08f OK 2025/03/11 07:28:48 DEBUG : potato2: Need to transfer - File not found at Destination 2025/03/11 07:28:48 NOTICE: potato2: Skipped copy as --dry-run is set (size 60) 2025/03/11 07:28:48 DEBUG : empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/03/11 07:28:48 DEBUG : empty space: Unchanged skipping 2025/03/11 07:28:48 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pefewaw2dupe': Waiting for checks to finish 2025/03/11 07:28:48 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pefewaw2dupe': Waiting for transfers to finish 2025/03/11 07:28:48 DEBUG : Waiting for deletions to finish 2025/03/11 07:28:48 NOTICE: potato: Skipped delete as --dry-run is set (size 21) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pefewaw2dupe'", Local "Local file system at /tmp/rclone22493455", Modify Window "1ms" --- PASS: TestSyncAfterRemovingAFileAndAddingAFileDryRun (5.21s) === RUN TestSyncAfterRemovingAFileAndAddingAFile run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pefewaw2dupe'", Local "Local file system at /tmp/rclone22493455", Modify Window "1ms" 2025/03/11 07:28:51 DEBUG : potato: md5 = a94c5a8bb9c4a1bb08834bc4c73b2e8d OK 2025/03/11 07:28:53 DEBUG : empty space: md5 = 8452d0a01ba2b3b27380a8d2aefd535b OK 2025/03/11 07:28:53 DEBUG : potato2: Need to transfer - File not found at Destination 2025/03/11 07:28:53 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pefewaw2dupe': Waiting for checks to finish 2025/03/11 07:28:53 DEBUG : empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/03/11 07:28:53 DEBUG : empty space: Unchanged skipping 2025/03/11 07:28:53 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pefewaw2dupe': Waiting for transfers to finish 2025/03/11 07:28:55 DEBUG : potato2: md5 = 9da7e25654168c0d631833374bbf1bb4 OK 2025/03/11 07:28:55 INFO : potato2: Copied (new) 2025/03/11 07:28:55 DEBUG : Waiting for deletions to finish 2025/03/11 07:28:55 INFO : potato: Deleted run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pefewaw2dupe'", Local "Local file system at /tmp/rclone22493455", Modify Window "1ms" --- PASS: TestSyncAfterRemovingAFileAndAddingAFile (7.28s) === RUN TestSyncAfterRemovingAFileAndAddingAFileSubDir run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pefewaw2dupe'", Local "Local file system at /tmp/rclone22493455", Modify Window "1ms" 2025/03/11 07:28:59 DEBUG : b/potato: md5 = f3dd107c5035cd465e8f2aa2aacd8c06 OK 2025/03/11 07:29:02 DEBUG : c/non empty space: md5 = e5f924ab698cca9f02b1b9c0e842e974 OK 2025/03/11 07:29:02 INFO : d: Making directory 2025/03/11 07:29:02 INFO : d/e: Making directory 2025/03/11 07:29:05 DEBUG : Added delayed dir = "a", newDst= 2025/03/11 07:29:05 INFO : c: Set directory modification time (using SetModTime) 2025/03/11 07:29:05 DEBUG : Added delayed dir = "c", newDst=c 2025/03/11 07:29:05 DEBUG : c/non empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/03/11 07:29:05 DEBUG : a/potato2: Need to transfer - File not found at Destination 2025/03/11 07:29:05 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pefewaw2dupe': Waiting for checks to finish 2025/03/11 07:29:05 DEBUG : c/non empty space: Unchanged skipping 2025/03/11 07:29:05 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pefewaw2dupe': Waiting for transfers to finish 2025/03/11 07:29:07 DEBUG : a/potato2: md5 = 01159224ad31f843cc6f515d6b1a7097 OK 2025/03/11 07:29:07 INFO : a/potato2: Copied (new) 2025/03/11 07:29:07 DEBUG : Waiting for deletions to finish 2025/03/11 07:29:08 INFO : b/potato: Deleted 2025/03/11 07:29:08 INFO : a: Set directory modification time (using DirSetModTime) 2025/03/11 07:29:08 INFO : d/e: Removing directory 2025/03/11 07:29:09 INFO : d: Removing directory 2025/03/11 07:29:09 DEBUG : ka6id8d20d3s5ktapedlphgta8: Rmdir: contains trashed file: "r8sppajuabeak3sbgj2ak8vuf8" 2025/03/11 07:29:10 INFO : b: Removing directory 2025/03/11 07:29:10 DEBUG : 32d8ua6196mc1r7qkfog53rkg0: Rmdir: contains trashed file: "2m507n64kafsi59v9q71r281a4" 2025/03/11 07:29:11 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pefewaw2dupe': deleted 3 directories run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pefewaw2dupe'", Local "Local file system at /tmp/rclone22493455", Modify Window "1ms" 2025/03/11 07:29:13 DEBUG : 3i9du405pfogq3ncai6pg7ouio: Rmdir: contains trashed file: "982d3pss7t5pn0il16r2foj31s" 2025/03/11 07:29:13 DEBUG : 2bsvlrk2ne1lfitm6tttcu0qt8: Rmdir: contains trashed file: "89l8renevh3mji1c8r1p7qn6tg" --- PASS: TestSyncAfterRemovingAFileAndAddingAFileSubDir (17.25s) === RUN TestSyncAfterRemovingAFileAndAddingAFileSubDirWithErrors run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pefewaw2dupe'", Local "Local file system at /tmp/rclone22493455", Modify Window "1ms" 2025/03/11 07:29:17 DEBUG : b/potato: md5 = 7039a65f3375a5dd2d3f23836f984e73 OK 2025/03/11 07:29:19 DEBUG : c/non empty space: md5 = f0be345e78d6ff3091e982ea77178e8b OK 2025/03/11 07:29:19 INFO : d: Making directory 2025/03/11 07:29:21 DEBUG : Added delayed dir = "a", newDst= 2025/03/11 07:29:21 INFO : c: Set directory modification time (using SetModTime) 2025/03/11 07:29:21 DEBUG : Added delayed dir = "c", newDst=c 2025/03/11 07:29:21 DEBUG : c/non empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/03/11 07:29:21 DEBUG : c/non empty space: Unchanged skipping 2025/03/11 07:29:21 DEBUG : a/potato2: Need to transfer - File not found at Destination 2025/03/11 07:29:21 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pefewaw2dupe': Waiting for checks to finish 2025/03/11 07:29:21 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pefewaw2dupe': Waiting for transfers to finish 2025/03/11 07:29:23 DEBUG : a/potato2: md5 = 4609344fd9fb4e0c8d3466c1ae49eedc OK 2025/03/11 07:29:23 INFO : a/potato2: Copied (new) 2025/03/11 07:29:23 ERROR : Encrypted drive 'TestCryptDrive:rclone-test-pefewaw2dupe': not deleting files as there were IO errors 2025/03/11 07:29:24 INFO : a: Set directory modification time (using DirSetModTime) 2025/03/11 07:29:24 ERROR : Encrypted drive 'TestCryptDrive:rclone-test-pefewaw2dupe': not deleting directories as there were IO errors run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pefewaw2dupe'", Local "Local file system at /tmp/rclone22493455", Modify Window "1ms" 2025/03/11 07:29:28 DEBUG : 3i9du405pfogq3ncai6pg7ouio: Rmdir: contains trashed file: "982d3pss7t5pn0il16r2foj31s" 2025/03/11 07:29:28 DEBUG : 32d8ua6196mc1r7qkfog53rkg0: Rmdir: contains trashed file: "2m507n64kafsi59v9q71r281a4" 2025/03/11 07:29:29 DEBUG : 2bsvlrk2ne1lfitm6tttcu0qt8: Rmdir: contains trashed file: "89l8renevh3mji1c8r1p7qn6tg" --- PASS: TestSyncAfterRemovingAFileAndAddingAFileSubDirWithErrors (16.01s) === RUN TestSyncDeleteAfter --- PASS: TestSyncDeleteAfter (0.00s) === RUN TestSyncDeleteDuring run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pefewaw2dupe'", Local "Local file system at /tmp/rclone22493455", Modify Window "1ms" 2025/03/11 07:29:32 DEBUG : potato: md5 = 2b531272168502bfefc392cd3876f402 OK 2025/03/11 07:29:33 DEBUG : empty space: md5 = 472d203b9df5c428988c23f8c8527869 OK 2025/03/11 07:29:34 DEBUG : Waiting for deletions to finish 2025/03/11 07:29:34 DEBUG : potato2: Need to transfer - File not found at Destination 2025/03/11 07:29:34 DEBUG : empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/03/11 07:29:34 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pefewaw2dupe': Waiting for checks to finish 2025/03/11 07:29:34 DEBUG : empty space: Unchanged skipping 2025/03/11 07:29:34 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pefewaw2dupe': Waiting for transfers to finish 2025/03/11 07:29:34 INFO : potato: Deleted 2025/03/11 07:29:35 DEBUG : potato2: md5 = a63583fc794000dd9ce560800a10ab3f OK 2025/03/11 07:29:35 INFO : potato2: Copied (new) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pefewaw2dupe'", Local "Local file system at /tmp/rclone22493455", Modify Window "1ms" --- PASS: TestSyncDeleteDuring (6.99s) === RUN TestSyncDeleteBefore run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pefewaw2dupe'", Local "Local file system at /tmp/rclone22493455", Modify Window "1ms" 2025/03/11 07:29:39 DEBUG : potato: md5 = 6e7be4fea61414e588a4c3a27ec03018 OK 2025/03/11 07:29:40 DEBUG : empty space: md5 = 37e3f4bd46fc0eedc7e3787bb3804fbe OK 2025/03/11 07:29:41 DEBUG : Waiting for deletions to finish 2025/03/11 07:29:41 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pefewaw2dupe': Waiting for checks to finish 2025/03/11 07:29:41 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pefewaw2dupe': Waiting for transfers to finish 2025/03/11 07:29:41 INFO : potato: Deleted 2025/03/11 07:29:42 DEBUG : potato2: Need to transfer - File not found at Destination 2025/03/11 07:29:42 DEBUG : empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/03/11 07:29:42 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pefewaw2dupe': Waiting for checks to finish 2025/03/11 07:29:42 DEBUG : empty space: Unchanged skipping 2025/03/11 07:29:42 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pefewaw2dupe': Waiting for transfers to finish 2025/03/11 07:29:43 DEBUG : potato2: md5 = 4a6f4811fdfec5d737d8f594a2c8057e OK 2025/03/11 07:29:43 INFO : potato2: Copied (new) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pefewaw2dupe'", Local "Local file system at /tmp/rclone22493455", Modify Window "1ms" --- PASS: TestSyncDeleteBefore (8.08s) === RUN TestCopyDeleteBefore run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pefewaw2dupe'", Local "Local file system at /tmp/rclone22493455", Modify Window "1ms" 2025/03/11 07:29:47 DEBUG : potato: md5 = fb86e049e54974369c29643349870bca OK 2025/03/11 07:29:48 DEBUG : potato2: Need to transfer - File not found at Destination 2025/03/11 07:29:48 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pefewaw2dupe': Waiting for checks to finish 2025/03/11 07:29:48 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pefewaw2dupe': Waiting for transfers to finish 2025/03/11 07:29:49 DEBUG : potato2: md5 = 7e6eb939cba6e3fe6f9a5d8f4d29b009 OK 2025/03/11 07:29:49 INFO : potato2: Copied (new) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pefewaw2dupe'", Local "Local file system at /tmp/rclone22493455", Modify Window "1ms" --- PASS: TestCopyDeleteBefore (5.29s) === RUN TestSyncWithExclude run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pefewaw2dupe'", Local "Local file system at /tmp/rclone22493455", Modify Window "1ms" 2025/03/11 07:29:52 DEBUG : potato2: md5 = 4c3a54e33a38ec396106bc331553544d OK 2025/03/11 07:29:54 DEBUG : empty space: md5 = f55ea5a67a94d120cc09bd4ff01e6648 OK 2025/03/11 07:29:54 DEBUG : enormous: Excluded (Size Filter) 2025/03/11 07:29:54 DEBUG : enormous: Excluded 2025/03/11 07:29:54 DEBUG : potato2: Excluded (Size Filter) 2025/03/11 07:29:54 DEBUG : potato2: Excluded 2025/03/11 07:29:54 DEBUG : potato2: Excluded (Size Filter) 2025/03/11 07:29:54 DEBUG : empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/03/11 07:29:54 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pefewaw2dupe': Waiting for checks to finish 2025/03/11 07:29:54 DEBUG : empty space: Unchanged skipping 2025/03/11 07:29:54 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pefewaw2dupe': Waiting for transfers to finish 2025/03/11 07:29:54 DEBUG : Waiting for deletions to finish 2025/03/11 07:29:54 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pefewaw2dupe'", Local "Local file system at /tmp/rclone22493455", Modify Window "1ms" 2025/03/11 07:29:55 DEBUG : enormous: Excluded (Size Filter) 2025/03/11 07:29:55 DEBUG : enormous: Excluded 2025/03/11 07:29:55 DEBUG : potato2: Excluded (Size Filter) 2025/03/11 07:29:55 DEBUG : potato2: Excluded 2025/03/11 07:29:55 DEBUG : potato2: Excluded (Size Filter) 2025/03/11 07:29:55 DEBUG : empty space: Size and modification time the same (differ by 456.789µs, within tolerance 1ms) 2025/03/11 07:29:55 DEBUG : empty space: Unchanged skipping 2025/03/11 07:29:55 DEBUG : Local file system at /tmp/rclone22493455: Waiting for checks to finish 2025/03/11 07:29:55 DEBUG : Local file system at /tmp/rclone22493455: Waiting for transfers to finish 2025/03/11 07:29:55 DEBUG : Waiting for deletions to finish 2025/03/11 07:29:55 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pefewaw2dupe'", Local "Local file system at /tmp/rclone22493455", Modify Window "1ms" --- PASS: TestSyncWithExclude (6.35s) === RUN TestSyncWithExcludeAndDeleteExcluded run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pefewaw2dupe'", Local "Local file system at /tmp/rclone22493455", Modify Window "1ms" 2025/03/11 07:29:59 DEBUG : potato2: md5 = b97d4e81a1f5a120156a98d7f1043fe6 OK 2025/03/11 07:30:00 DEBUG : empty space: md5 = db817a1c2c35e4711fbeedbf626f4053 OK 2025/03/11 07:30:02 DEBUG : enormous: md5 = 05da97444bb9cfd0c37e59c6cffd010e OK 2025/03/11 07:30:02 DEBUG : enormous: Excluded (Size Filter) 2025/03/11 07:30:02 DEBUG : enormous: Excluded 2025/03/11 07:30:02 DEBUG : potato2: Excluded (Size Filter) 2025/03/11 07:30:02 DEBUG : potato2: Excluded 2025/03/11 07:30:02 DEBUG : empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/03/11 07:30:02 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pefewaw2dupe': Waiting for checks to finish 2025/03/11 07:30:02 DEBUG : empty space: Unchanged skipping 2025/03/11 07:30:02 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pefewaw2dupe': Waiting for transfers to finish 2025/03/11 07:30:02 DEBUG : Waiting for deletions to finish 2025/03/11 07:30:03 INFO : potato2: Deleted 2025/03/11 07:30:03 INFO : enormous: Deleted 2025/03/11 07:30:03 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pefewaw2dupe'", Local "Local file system at /tmp/rclone22493455", Modify Window "1ms" 2025/03/11 07:30:03 DEBUG : empty space: Size and modification time the same (differ by 456.789µs, within tolerance 1ms) 2025/03/11 07:30:03 DEBUG : empty space: Unchanged skipping 2025/03/11 07:30:03 DEBUG : Local file system at /tmp/rclone22493455: Waiting for checks to finish 2025/03/11 07:30:03 DEBUG : Local file system at /tmp/rclone22493455: Waiting for transfers to finish 2025/03/11 07:30:03 DEBUG : Waiting for deletions to finish 2025/03/11 07:30:03 INFO : enormous: Deleted 2025/03/11 07:30:03 INFO : potato2: Deleted 2025/03/11 07:30:03 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pefewaw2dupe'", Local "Local file system at /tmp/rclone22493455", Modify Window "1ms" --- PASS: TestSyncWithExcludeAndDeleteExcluded (7.69s) === RUN TestSyncWithUpdateOlder run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pefewaw2dupe'", Local "Local file system at /tmp/rclone22493455", Modify Window "1ms" 2025/03/11 07:30:06 DEBUG : one: md5 = 1b76e7e237e9626b75566ef5344431c0 OK 2025/03/11 07:30:08 DEBUG : two: md5 = d3ddf70ac87ab0cf3c020fcd68094327 OK 2025/03/11 07:30:09 DEBUG : three: md5 = bc03737ddb53b56a821a9e1174d6f01d OK 2025/03/11 07:30:10 DEBUG : four: md5 = fe5fbc2117e641566384dfe86c1ab55f OK 2025/03/11 07:30:11 DEBUG : five: Need to transfer - File not found at Destination 2025/03/11 07:30:11 DEBUG : four: Sizes differ (src 4 vs dst 8) 2025/03/11 07:30:11 DEBUG : one: Destination is newer than source, skipping 2025/03/11 07:30:11 DEBUG : three: Sizes identical 2025/03/11 07:30:11 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pefewaw2dupe': Waiting for checks to finish 2025/03/11 07:30:11 DEBUG : four: Destination mod time is within 1s of source but files differ, transferring 2025/03/11 07:30:11 DEBUG : three: Destination mod time is within 1s of source and files identical, skipping 2025/03/11 07:30:11 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pefewaw2dupe': Waiting for transfers to finish 2025/03/11 07:30:12 DEBUG : two: md5 = 623dc48d1d2085cfeab333fe98841c82 OK 2025/03/11 07:30:12 INFO : two: Copied (replaced existing) 2025/03/11 07:30:12 DEBUG : five: md5 = 5f30c588b10023614a009ac4a5abfa44 OK 2025/03/11 07:30:12 INFO : five: Copied (new) 2025/03/11 07:30:12 DEBUG : four: md5 = 57a4a59ab70da03cdd9f86a98afdc995 OK 2025/03/11 07:30:12 INFO : four: Copied (replaced existing) 2025/03/11 07:30:12 DEBUG : Waiting for deletions to finish sync_test.go:1449: Skip test with --checksum as no hashes supported --- PASS: TestSyncWithUpdateOlder (10.34s) === 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-pefewaw2dupe'", Local "Local file system at /tmp/rclone22493455", Modify Window "1ms" sync_test.go:1538: Can track renames: false 2025/03/11 07:30:15 ERROR : Encrypted drive 'TestCryptDrive:rclone-test-pefewaw2dupe': Ignoring --track-renames as the source and destination do not have a common hash 2025/03/11 07:30:16 DEBUG : potato: Need to transfer - File not found at Destination 2025/03/11 07:30:16 DEBUG : yam: Need to transfer - File not found at Destination 2025/03/11 07:30:16 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pefewaw2dupe': Waiting for checks to finish 2025/03/11 07:30:16 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pefewaw2dupe': Waiting for transfers to finish 2025/03/11 07:30:17 DEBUG : yam: md5 = 446d26fe5577f0cbbbef3b49079959ce OK 2025/03/11 07:30:17 INFO : yam: Copied (new) 2025/03/11 07:30:17 DEBUG : potato: md5 = 918f216e3d11258ffb537a4d82b2acda OK 2025/03/11 07:30:17 INFO : potato: Copied (new) 2025/03/11 07:30:17 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pefewaw2dupe'", Local "Local file system at /tmp/rclone22493455", Modify Window "1ms" 2025/03/11 07:30:17 ERROR : Encrypted drive 'TestCryptDrive:rclone-test-pefewaw2dupe': Ignoring --track-renames as the source and destination do not have a common hash 2025/03/11 07:30:18 DEBUG : yaml: Need to transfer - File not found at Destination 2025/03/11 07:30:18 DEBUG : potato: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/03/11 07:30:18 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pefewaw2dupe': Waiting for checks to finish 2025/03/11 07:30:18 DEBUG : potato: Unchanged skipping 2025/03/11 07:30:18 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pefewaw2dupe': Waiting for transfers to finish 2025/03/11 07:30:19 DEBUG : yaml: md5 = 6a79c8f34f83b9ee1290a8ccbf503030 OK 2025/03/11 07:30:19 INFO : yaml: Copied (new) 2025/03/11 07:30:19 DEBUG : Waiting for deletions to finish 2025/03/11 07:30:20 INFO : yam: Deleted run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pefewaw2dupe'", Local "Local file system at /tmp/rclone22493455", Modify Window "1ms" --- PASS: TestSyncWithTrackRenames (7.31s) === RUN TestParseRenamesStrategyModtime --- PASS: TestParseRenamesStrategyModtime (0.00s) === RUN TestRenamesStrategyModtime --- PASS: TestRenamesStrategyModtime (0.00s) === RUN TestSyncWithTrackRenamesStrategyModtime run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pefewaw2dupe'", Local "Local file system at /tmp/rclone22493455", Modify Window "1ms" sync_test.go:1610: Can track renames: true 2025/03/11 07:30:23 INFO : Encrypted drive 'TestCryptDrive:rclone-test-pefewaw2dupe': Making map for --track-renames 2025/03/11 07:30:23 INFO : Encrypted drive 'TestCryptDrive:rclone-test-pefewaw2dupe': Finished making map for --track-renames 2025/03/11 07:30:23 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pefewaw2dupe': Waiting for checks to finish 2025/03/11 07:30:23 DEBUG : potato: Need to transfer - No matching file found at Destination 2025/03/11 07:30:23 DEBUG : yam: Need to transfer - No matching file found at Destination 2025/03/11 07:30:23 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pefewaw2dupe': Waiting for renames to finish 2025/03/11 07:30:23 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pefewaw2dupe': Waiting for transfers to finish 2025/03/11 07:30:24 DEBUG : potato: md5 = 38a76ca849d8405505f06df6268660f3 OK 2025/03/11 07:30:24 INFO : potato: Copied (new) 2025/03/11 07:30:24 DEBUG : yam: md5 = 761811bc4f09000e357ec050efef2f0a OK 2025/03/11 07:30:24 INFO : yam: Copied (new) 2025/03/11 07:30:24 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pefewaw2dupe'", Local "Local file system at /tmp/rclone22493455", Modify Window "1ms" 2025/03/11 07:30:25 DEBUG : potato: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/03/11 07:30:25 INFO : Encrypted drive 'TestCryptDrive:rclone-test-pefewaw2dupe': Making map for --track-renames 2025/03/11 07:30:25 INFO : Encrypted drive 'TestCryptDrive:rclone-test-pefewaw2dupe': Finished making map for --track-renames 2025/03/11 07:30:25 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pefewaw2dupe': Waiting for checks to finish 2025/03/11 07:30:25 DEBUG : potato: Unchanged skipping 2025/03/11 07:30:25 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pefewaw2dupe': Waiting for renames to finish 2025/03/11 07:30:25 INFO : yam: Moved (server-side) to: yaml 2025/03/11 07:30:25 INFO : yaml: Renamed from "yam" 2025/03/11 07:30:25 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pefewaw2dupe': Waiting for transfers to finish 2025/03/11 07:30:25 DEBUG : Waiting for deletions to finish 2025/03/11 07:30:25 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pefewaw2dupe'", Local "Local file system at /tmp/rclone22493455", Modify Window "1ms" --- PASS: TestSyncWithTrackRenamesStrategyModtime (5.34s) === RUN TestSyncWithTrackRenamesStrategyLeaf run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pefewaw2dupe'", Local "Local file system at /tmp/rclone22493455", Modify Window "1ms" sync_test.go:1649: Can track renames: true 2025/03/11 07:30:28 DEBUG : Added delayed dir = "sub", newDst= 2025/03/11 07:30:28 INFO : Encrypted drive 'TestCryptDrive:rclone-test-pefewaw2dupe': Making map for --track-renames 2025/03/11 07:30:28 INFO : Encrypted drive 'TestCryptDrive:rclone-test-pefewaw2dupe': Finished making map for --track-renames 2025/03/11 07:30:28 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pefewaw2dupe': Waiting for checks to finish 2025/03/11 07:30:28 DEBUG : potato: Need to transfer - No matching file found at Destination 2025/03/11 07:30:28 DEBUG : sub/yam: Need to transfer - No matching file found at Destination 2025/03/11 07:30:28 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pefewaw2dupe': Waiting for renames to finish 2025/03/11 07:30:28 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pefewaw2dupe': Waiting for transfers to finish 2025/03/11 07:30:30 DEBUG : potato: md5 = cc23f13434ff3be52f9f630722e267ea OK 2025/03/11 07:30:30 INFO : potato: Copied (new) 2025/03/11 07:30:30 DEBUG : sub/yam: md5 = 6ecee31cddd27e12f37007b04608cfd5 OK 2025/03/11 07:30:30 INFO : sub/yam: Copied (new) 2025/03/11 07:30:30 DEBUG : Waiting for deletions to finish 2025/03/11 07:30:31 INFO : sub: Set directory modification time (using DirSetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pefewaw2dupe'", Local "Local file system at /tmp/rclone22493455", Modify Window "1ms" 2025/03/11 07:30:32 DEBUG : potato: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/03/11 07:30:32 DEBUG : potato: Unchanged skipping 2025/03/11 07:30:33 INFO : sub: Set directory modification time (using SetModTime) 2025/03/11 07:30:33 DEBUG : Added delayed dir = "sub", newDst=sub 2025/03/11 07:30:33 INFO : Encrypted drive 'TestCryptDrive:rclone-test-pefewaw2dupe': Making map for --track-renames 2025/03/11 07:30:33 INFO : Encrypted drive 'TestCryptDrive:rclone-test-pefewaw2dupe': Finished making map for --track-renames 2025/03/11 07:30:33 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pefewaw2dupe': Waiting for checks to finish 2025/03/11 07:30:33 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pefewaw2dupe': Waiting for renames to finish 2025/03/11 07:30:33 INFO : sub/yam: Moved (server-side) to: yam 2025/03/11 07:30:33 INFO : yam: Renamed from "sub/yam" 2025/03/11 07:30:33 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pefewaw2dupe': Waiting for transfers to finish 2025/03/11 07:30:33 DEBUG : Waiting for deletions to finish 2025/03/11 07:30:33 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pefewaw2dupe'", Local "Local file system at /tmp/rclone22493455", Modify Window "1ms" --- PASS: TestSyncWithTrackRenamesStrategyLeaf (9.44s) === RUN TestServerSideMoveLocal run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pefewaw2dupe'", Local "Local file system at /tmp/rclone22493455", Modify Window "1ms" 2025/03/11 07:30:37 DEBUG : Creating backend with remote "/tmp/rclone22493455/dir1" 2025/03/11 07:30:37 DEBUG : Config file has changed externally - reloading 2025/03/11 07:30:37 DEBUG : Creating backend with remote "/tmp/rclone22493455/dir2" 2025/03/11 07:30:37 DEBUG : Local file system at /tmp/rclone22493455/dir2: Using server-side directory move 2025/03/11 07:30:37 INFO : Local file system at /tmp/rclone22493455/dir2: Server side directory move failed - fallback to file moves: can't copy directory - destination already exists 2025/03/11 07:30:37 DEBUG : file1.txt: Need to transfer - File not found at Destination 2025/03/11 07:30:37 INFO : file1.txt: Moved (server-side) 2025/03/11 07:30:37 DEBUG : Local file system at /tmp/rclone22493455/dir2: Waiting for checks to finish 2025/03/11 07:30:37 DEBUG : Local file system at /tmp/rclone22493455/dir2: Waiting for transfers to finish --- PASS: TestServerSideMoveLocal (0.51s) === RUN TestMoveWithDeleteEmptySrcDirs run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pefewaw2dupe'", Local "Local file system at /tmp/rclone22493455", Modify Window "1ms" 2025/03/11 07:30:38 DEBUG : Added delayed dir = "nested", newDst= 2025/03/11 07:30:38 DEBUG : Added delayed dir = "sub dir", newDst= 2025/03/11 07:30:38 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2025/03/11 07:30:38 DEBUG : Added delayed dir = "nested/sub dir", newDst= 2025/03/11 07:30:38 DEBUG : nested/sub dir/file: Need to transfer - File not found at Destination 2025/03/11 07:30:38 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pefewaw2dupe': Waiting for checks to finish 2025/03/11 07:30:38 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pefewaw2dupe': Waiting for transfers to finish 2025/03/11 07:30:40 DEBUG : sub dir/hello world: md5 = 1f983cd0025b8463ebca2301d3b1f3c9 OK 2025/03/11 07:30:40 INFO : sub dir/hello world: Copied (new) 2025/03/11 07:30:40 INFO : sub dir/hello world: Deleted 2025/03/11 07:30:42 DEBUG : nested/sub dir/file: md5 = fa589ca6d2fdf334bdd0e710de26a81d OK 2025/03/11 07:30:42 INFO : nested/sub dir/file: Copied (new) 2025/03/11 07:30:42 INFO : nested/sub dir/file: Deleted 2025/03/11 07:30:43 INFO : nested/sub dir: Set directory modification time (using DirSetModTime) 2025/03/11 07:30:43 INFO : nested: Set directory modification time (using DirSetModTime) 2025/03/11 07:30:43 INFO : sub dir: Set directory modification time (using DirSetModTime) 2025/03/11 07:30:43 INFO : sub dir: Removing directory 2025/03/11 07:30:43 INFO : nested/sub dir: Removing directory 2025/03/11 07:30:43 INFO : nested: Removing directory 2025/03/11 07:30:43 DEBUG : Local file system at /tmp/rclone22493455: deleted 3 directories run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pefewaw2dupe'", Local "Local file system at /tmp/rclone22493455", Modify Window "1ms" 2025/03/11 07:30:46 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" 2025/03/11 07:30:47 DEBUG : 37qp6d1gohacv723ij3brofbu8/14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "ftp4kuv8se7tqduu6pmmcvjsmk" 2025/03/11 07:30:47 DEBUG : 37qp6d1gohacv723ij3brofbu8: Rmdir: contains trashed file: "14begaa36ih249fgrnfk6nulg0" --- PASS: TestMoveWithDeleteEmptySrcDirs (10.51s) === RUN TestMoveWithoutDeleteEmptySrcDirs run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pefewaw2dupe'", Local "Local file system at /tmp/rclone22493455", Modify Window "1ms" 2025/03/11 07:30:49 DEBUG : Added delayed dir = "nested", newDst= 2025/03/11 07:30:49 DEBUG : Added delayed dir = "sub dir", newDst= 2025/03/11 07:30:49 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2025/03/11 07:30:49 DEBUG : Added delayed dir = "nested/sub dir", newDst= 2025/03/11 07:30:49 DEBUG : nested/sub dir/file: Need to transfer - File not found at Destination 2025/03/11 07:30:49 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pefewaw2dupe': Waiting for checks to finish 2025/03/11 07:30:49 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pefewaw2dupe': Waiting for transfers to finish 2025/03/11 07:30:51 DEBUG : sub dir/hello world: md5 = fc7393b61bdd34dd35b301ce53135337 OK 2025/03/11 07:30:51 INFO : sub dir/hello world: Copied (new) 2025/03/11 07:30:51 INFO : sub dir/hello world: Deleted 2025/03/11 07:30:53 DEBUG : nested/sub dir/file: md5 = 6dceeb1bb537b11ba1950a2b2afef96a OK 2025/03/11 07:30:53 INFO : nested/sub dir/file: Copied (new) 2025/03/11 07:30:53 INFO : nested/sub dir/file: Deleted 2025/03/11 07:30:53 INFO : nested/sub dir: Set directory modification time (using DirSetModTime) 2025/03/11 07:30:54 INFO : sub dir: Set directory modification time (using DirSetModTime) 2025/03/11 07:30:54 INFO : nested: Set directory modification time (using DirSetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pefewaw2dupe'", Local "Local file system at /tmp/rclone22493455", Modify Window "1ms" 2025/03/11 07:30:57 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" 2025/03/11 07:30:57 DEBUG : 37qp6d1gohacv723ij3brofbu8/14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "ftp4kuv8se7tqduu6pmmcvjsmk" 2025/03/11 07:30:58 DEBUG : 37qp6d1gohacv723ij3brofbu8: Rmdir: contains trashed file: "14begaa36ih249fgrnfk6nulg0" --- PASS: TestMoveWithoutDeleteEmptySrcDirs (10.76s) === RUN TestMoveWithIgnoreExisting run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pefewaw2dupe'", Local "Local file system at /tmp/rclone22493455", Modify Window "1ms" 2025/03/11 07:30:59 DEBUG : existing: Need to transfer - File not found at Destination 2025/03/11 07:30:59 DEBUG : existing-b: Need to transfer - File not found at Destination 2025/03/11 07:30:59 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pefewaw2dupe': Waiting for checks to finish 2025/03/11 07:30:59 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pefewaw2dupe': Waiting for transfers to finish 2025/03/11 07:31:01 DEBUG : existing-b: md5 = 9fea60a14aa953f2d1b0ad1c04ee038a OK 2025/03/11 07:31:01 INFO : existing-b: Copied (new) 2025/03/11 07:31:01 INFO : existing-b: Deleted 2025/03/11 07:31:01 DEBUG : existing: md5 = bef99b07fd8aefe976677874fd5fce90 OK 2025/03/11 07:31:01 INFO : existing: Copied (new) 2025/03/11 07:31:01 INFO : existing: Deleted 2025/03/11 07:31:02 DEBUG : existing: Destination exists, skipping 2025/03/11 07:31:02 DEBUG : existing: Not removing source file as destination file exists and --ignore-existing is set 2025/03/11 07:31:02 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pefewaw2dupe': Waiting for checks to finish 2025/03/11 07:31:02 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pefewaw2dupe': Waiting for transfers to finish 2025/03/11 07:31:02 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pefewaw2dupe'", Local "Local file system at /tmp/rclone22493455", Modify Window "1ms" --- PASS: TestMoveWithIgnoreExisting (4.62s) === RUN TestServerSideMove run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pefewaw2dupe'", Local "Local file system at /tmp/rclone22493455", Modify Window "1ms" 2025/03/11 07:31:04 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-remeyoz3fanu" 2025/03/11 07:31:04 DEBUG : Config file has changed externally - reloading 2025/03/11 07:31:04 DEBUG : Creating backend with remote "TestDrive:crypt/3tabg9v5ero1t3rlmalts6hlich1jjlkk3l1jv06hnk1hmtvahtg" 2025/03/11 07:31:06 DEBUG : potato2: md5 = 9e71439faeae01e470b47d53f613f4cb OK 2025/03/11 07:31:08 DEBUG : empty space: md5 = 0ea00efb06da48bbfea3a5fcf81ec86d OK 2025/03/11 07:31:09 DEBUG : potato3: md5 = 79fc0638e983f6da3879fcce5fad0d4a OK sync_test.go:1705: Server side move (if possible) Encrypted drive 'TestCryptDrive:rclone-test-pefewaw2dupe' -> Encrypted drive 'TestCryptDrive:rclone-test-remeyoz3fanu' 2025/03/11 07:31:12 DEBUG : empty space: md5 = ef6b0dd7633edbc9bb54beb6b8750c5a OK 2025/03/11 07:31:13 DEBUG : potato3: md5 = e43fb498196bf6e9711a65be2c8c9d8e OK 2025/03/11 07:31:13 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-remeyoz3fanu': Using server-side directory move 2025/03/11 07:31:13 INFO : Encrypted drive 'TestCryptDrive:rclone-test-remeyoz3fanu': Server side directory move failed - fallback to file moves: can't copy directory - destination already exists 2025/03/11 07:31:14 DEBUG : potato2: Need to transfer - File not found at Destination 2025/03/11 07:31:14 DEBUG : empty space: Size and modification time the same (differ by 0s, within tolerance 1ms) 2025/03/11 07:31:14 DEBUG : empty space: Unchanged skipping 2025/03/11 07:31:14 DEBUG : potato3: Sizes differ (src 68 vs dst 60) 2025/03/11 07:31:14 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-remeyoz3fanu': Waiting for checks to finish 2025/03/11 07:31:14 INFO : potato3: Deleted 2025/03/11 07:31:14 INFO : empty space: Deleted 2025/03/11 07:31:14 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-remeyoz3fanu': Waiting for transfers to finish 2025/03/11 07:31:14 INFO : potato2: Moved (server-side) 2025/03/11 07:31:15 INFO : potato3: Moved (server-side) 2025/03/11 07:31:15 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-rabozan5tedu" 2025/03/11 07:31:15 DEBUG : Creating backend with remote "TestDrive:crypt/e2702o0aghd2670949amtjm57ian3j7mqofvsmfcue0cn265qhj0" 2025/03/11 07:31:16 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-rabozan5tedu': Using server-side directory move 2025/03/11 07:31:17 INFO : Encrypted drive 'TestCryptDrive:rclone-test-rabozan5tedu': Server side directory move succeeded 2025/03/11 07:31:18 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-rabozan5tedu': Purge remote 2025/03/11 07:31:18 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-remeyoz3fanu': Purge remote 2025/03/11 07:31:19 NOTICE: purge failed: directory not found --- PASS: TestServerSideMove (15.32s) === RUN TestServerSideMoveWithFilter run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pefewaw2dupe'", Local "Local file system at /tmp/rclone22493455", Modify Window "1ms" 2025/03/11 07:31:19 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-nusitog5vuvu" 2025/03/11 07:31:19 DEBUG : Creating backend with remote "TestDrive:crypt/el086vkvg795cuhuhl6ikce88c9pnkhhs5cqlv0t8oa3di7m6jag" 2025/03/11 07:31:22 DEBUG : potato2: md5 = 104695c95c5bba74b975c897fbdcb241 OK 2025/03/11 07:31:23 DEBUG : empty space: md5 = 44b0cd3c369c175b6bb5088c3adbc07b OK 2025/03/11 07:31:25 DEBUG : potato3: md5 = f2e986a9526571f74a6b3e617deb3d79 OK sync_test.go:1705: Server side move (if possible) Encrypted drive 'TestCryptDrive:rclone-test-pefewaw2dupe' -> Encrypted drive 'TestCryptDrive:rclone-test-nusitog5vuvu' 2025/03/11 07:31:27 DEBUG : empty space: md5 = 38f290860898046ebad7bbc0ab1329eb OK 2025/03/11 07:31:28 DEBUG : potato3: md5 = 999b888608673a978af5765074804db2 OK 2025/03/11 07:31:29 DEBUG : empty space: Excluded (Size Filter) 2025/03/11 07:31:29 DEBUG : empty space: Excluded (Size Filter) 2025/03/11 07:31:29 DEBUG : potato2: Need to transfer - File not found at Destination 2025/03/11 07:31:29 DEBUG : potato3: Sizes differ (src 68 vs dst 60) 2025/03/11 07:31:29 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-nusitog5vuvu': Waiting for checks to finish 2025/03/11 07:31:29 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-nusitog5vuvu': Waiting for transfers to finish 2025/03/11 07:31:29 INFO : potato3: Deleted 2025/03/11 07:31:30 INFO : potato2: Moved (server-side) 2025/03/11 07:31:30 INFO : potato3: Moved (server-side) 2025/03/11 07:31:31 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-zesupik3gane" 2025/03/11 07:31:31 DEBUG : Creating backend with remote "TestDrive:crypt/u8ojojp2c5268unt7b8b9glgak611aosuc0ait27asmrqarvpdd0" 2025/03/11 07:31:32 DEBUG : empty space: Excluded (Size Filter) 2025/03/11 07:31:32 DEBUG : potato2: Need to transfer - File not found at Destination 2025/03/11 07:31:32 DEBUG : potato3: Need to transfer - File not found at Destination 2025/03/11 07:31:32 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zesupik3gane': Waiting for checks to finish 2025/03/11 07:31:32 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zesupik3gane': Waiting for transfers to finish 2025/03/11 07:31:33 INFO : potato2: Moved (server-side) 2025/03/11 07:31:33 INFO : potato3: Moved (server-side) 2025/03/11 07:31:34 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zesupik3gane': Purge remote 2025/03/11 07:31:34 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-nusitog5vuvu': Purge remote --- PASS: TestServerSideMoveWithFilter (16.67s) === RUN TestServerSideMoveDeleteEmptySourceDirs run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pefewaw2dupe'", Local "Local file system at /tmp/rclone22493455", Modify Window "1ms" 2025/03/11 07:31:36 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-rumodix2tapo" 2025/03/11 07:31:36 DEBUG : Creating backend with remote "TestDrive:crypt/4priqje0dddt68h28fk5ds8ehvo8l1gd6ne2nnuu0sd1ietqbvbg" 2025/03/11 07:31:38 DEBUG : potato2: md5 = 419865f7dfdb035d543d7faeb291b9c0 OK 2025/03/11 07:31:39 DEBUG : empty space: md5 = 3027164042fffd05deb3a9f36e046506 OK 2025/03/11 07:31:41 DEBUG : potato3: md5 = 259187576c682b7b8ebdefc657865ed7 OK 2025/03/11 07:31:41 INFO : tomatoDir: Making directory sync_test.go:1705: Server side move (if possible) Encrypted drive 'TestCryptDrive:rclone-test-pefewaw2dupe' -> Encrypted drive 'TestCryptDrive:rclone-test-rumodix2tapo' 2025/03/11 07:31:45 DEBUG : empty space: md5 = bf2d2f9fbd13e3a36ad21f1069b5b74b OK 2025/03/11 07:31:46 DEBUG : potato3: md5 = 69ddcf5ce0dbe81618780db236b5def6 OK 2025/03/11 07:31:47 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-rumodix2tapo': Using server-side directory move 2025/03/11 07:31:47 INFO : Encrypted drive 'TestCryptDrive:rclone-test-rumodix2tapo': Server side directory move failed - fallback to file moves: can't copy directory - destination already exists 2025/03/11 07:31:47 DEBUG : potato2: Need to transfer - File not found at Destination 2025/03/11 07:31:47 DEBUG : Added delayed dir = "tomatoDir", newDst= 2025/03/11 07:31:47 DEBUG : empty space: Size and modification time the same (differ by 0s, within tolerance 1ms) 2025/03/11 07:31:47 DEBUG : empty space: Unchanged skipping 2025/03/11 07:31:47 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-rumodix2tapo': Waiting for checks to finish 2025/03/11 07:31:47 DEBUG : potato3: Sizes differ (src 68 vs dst 60) 2025/03/11 07:31:48 INFO : empty space: Deleted 2025/03/11 07:31:48 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-rumodix2tapo': Waiting for transfers to finish 2025/03/11 07:31:48 INFO : potato3: Deleted 2025/03/11 07:31:48 INFO : potato2: Moved (server-side) 2025/03/11 07:31:48 INFO : potato3: Moved (server-side) 2025/03/11 07:31:48 INFO : tomatoDir: Removing directory 2025/03/11 07:31:49 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pefewaw2dupe': deleted 1 directories 2025/03/11 07:31:50 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-kacugut3jiso" 2025/03/11 07:31:50 DEBUG : Creating backend with remote "TestDrive:crypt/8r72l3g4vm0hrcli7jfq3rb9t3vfitvkv18b21fu1cfu2iapnsmg" 2025/03/11 07:31:51 INFO : tomatoDir: Making directory 2025/03/11 07:31:51 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-kacugut3jiso': Using server-side directory move 2025/03/11 07:31:52 INFO : Encrypted drive 'TestCryptDrive:rclone-test-kacugut3jiso': Server side directory move succeeded 2025/03/11 07:31:54 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-kacugut3jiso': Purge remote 2025/03/11 07:31:54 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-rumodix2tapo': Purge remote 2025/03/11 07:31:54 NOTICE: purge failed: directory not found --- PASS: TestServerSideMoveDeleteEmptySourceDirs (19.05s) === RUN TestServerSideMoveOverlap run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pefewaw2dupe'", Local "Local file system at /tmp/rclone22493455", Modify Window "1ms" sync_test.go:1910: Skipping test as remote supports DirMove --- SKIP: TestServerSideMoveOverlap (0.48s) === RUN TestSyncOverlap run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pefewaw2dupe'", Local "Local file system at /tmp/rclone22493455", Modify Window "1ms" 2025/03/11 07:31:55 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-pefewaw2dupe/rclone-sync-test" 2025/03/11 07:31:55 DEBUG : Creating backend with remote "TestDrive:crypt/ksagmlv3rj5m8b0msrmbqotspumdk55608q89rcqpeo8k9oluq3g/i7355aa0sb89uagn75vfjqr6s3e3e1h2et8in57abn1fe8qfego0" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pefewaw2dupe'", Local "Local file system at /tmp/rclone22493455", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pefewaw2dupe'", Local "Local file system at /tmp/rclone22493455", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pefewaw2dupe'", Local "Local file system at /tmp/rclone22493455", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pefewaw2dupe'", Local "Local file system at /tmp/rclone22493455", Modify Window "1ms" --- PASS: TestSyncOverlap (3.96s) === RUN TestSyncOverlapWithFilter run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pefewaw2dupe'", Local "Local file system at /tmp/rclone22493455", Modify Window "1ms" 2025/03/11 07:31:59 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-pefewaw2dupe/rclone-sync-test" 2025/03/11 07:31:59 DEBUG : Creating backend with remote "TestDrive:crypt/ksagmlv3rj5m8b0msrmbqotspumdk55608q89rcqpeo8k9oluq3g/i7355aa0sb89uagn75vfjqr6s3e3e1h2et8in57abn1fe8qfego0" 2025/03/11 07:32:02 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-pefewaw2dupe/rclone-sync-test-include/layer2" 2025/03/11 07:32:02 DEBUG : Creating backend with remote "TestDrive:crypt/ksagmlv3rj5m8b0msrmbqotspumdk55608q89rcqpeo8k9oluq3g/khf2vlblvnbf9ftevqm0htmss73hj1j5a7q328e4ohrgs7e2loe0/n01jpl9202nn9ec1rb75h0f1c4" 2025/03/11 07:32:05 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-pefewaw2dupe/rclone-sync-test-ignore-file" 2025/03/11 07:32:05 DEBUG : Creating backend with remote "TestDrive:crypt/ksagmlv3rj5m8b0msrmbqotspumdk55608q89rcqpeo8k9oluq3g/kmf11jujl9uha3tjganvgpkn45bu778hb5vb5riug1c26b38k7sg" 2025/03/11 07:32:09 DEBUG : rclone-sync-test-ignore-file/.ignore: md5 = 53dea21940142a38b950d4ed54339206 OK 2025/03/11 07:32:11 DEBUG : Added delayed dir = "rclone-sync-test-include", newDst= 2025/03/11 07:32:11 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pefewaw2dupe/rclone-sync-test': Waiting for checks to finish 2025/03/11 07:32:11 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pefewaw2dupe/rclone-sync-test': Waiting for transfers to finish 2025/03/11 07:32:11 DEBUG : Waiting for deletions to finish 2025/03/11 07:32:11 INFO : There was nothing to transfer 2025/03/11 07:32:13 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pefewaw2dupe': Waiting for checks to finish 2025/03/11 07:32:13 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pefewaw2dupe': Waiting for transfers to finish 2025/03/11 07:32:13 DEBUG : Waiting for deletions to finish 2025/03/11 07:32:13 INFO : rclone-sync-test-include: Removing directory 2025/03/11 07:32:13 DEBUG : khf2vlblvnbf9ftevqm0htmss73hj1j5a7q328e4ohrgs7e2loe0: Rmdir: contains file: "n01jpl9202nn9ec1rb75h0f1c4" 2025/03/11 07:32:13 DEBUG : rclone-sync-test-include: Failed to Rmdir: directory not empty 2025/03/11 07:32:13 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pefewaw2dupe': failed to delete 1 directories 2025/03/11 07:32:13 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pefewaw2dupe'", Local "Local file system at /tmp/rclone22493455", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pefewaw2dupe'", Local "Local file system at /tmp/rclone22493455", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pefewaw2dupe'", Local "Local file system at /tmp/rclone22493455", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pefewaw2dupe'", Local "Local file system at /tmp/rclone22493455", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pefewaw2dupe'", Local "Local file system at /tmp/rclone22493455", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pefewaw2dupe'", Local "Local file system at /tmp/rclone22493455", Modify Window "1ms" 2025/03/11 07:32:15 DEBUG : Added delayed dir = "rclone-sync-test-include", newDst= 2025/03/11 07:32:15 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pefewaw2dupe/rclone-sync-test-include/layer2': Waiting for checks to finish 2025/03/11 07:32:15 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pefewaw2dupe/rclone-sync-test-include/layer2': Waiting for transfers to finish 2025/03/11 07:32:15 DEBUG : Waiting for deletions to finish 2025/03/11 07:32:15 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pefewaw2dupe'", Local "Local file system at /tmp/rclone22493455", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pefewaw2dupe'", Local "Local file system at /tmp/rclone22493455", Modify Window "1ms" 2025/03/11 07:32:17 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pefewaw2dupe': Waiting for checks to finish 2025/03/11 07:32:17 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pefewaw2dupe': Waiting for transfers to finish 2025/03/11 07:32:17 DEBUG : Waiting for deletions to finish 2025/03/11 07:32:17 INFO : rclone-sync-test-include: Removing directory 2025/03/11 07:32:17 DEBUG : khf2vlblvnbf9ftevqm0htmss73hj1j5a7q328e4ohrgs7e2loe0: Rmdir: contains file: "n01jpl9202nn9ec1rb75h0f1c4" 2025/03/11 07:32:17 DEBUG : rclone-sync-test-include: Failed to Rmdir: directory not empty 2025/03/11 07:32:17 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pefewaw2dupe': failed to delete 1 directories 2025/03/11 07:32:17 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pefewaw2dupe'", Local "Local file system at /tmp/rclone22493455", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pefewaw2dupe'", Local "Local file system at /tmp/rclone22493455", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pefewaw2dupe'", Local "Local file system at /tmp/rclone22493455", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pefewaw2dupe'", Local "Local file system at /tmp/rclone22493455", Modify Window "1ms" 2025/03/11 07:32:19 DEBUG : Added delayed dir = "rclone-sync-test-include", newDst= 2025/03/11 07:32:19 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pefewaw2dupe/rclone-sync-test-ignore-file': Waiting for checks to finish 2025/03/11 07:32:19 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pefewaw2dupe/rclone-sync-test-ignore-file': Waiting for transfers to finish 2025/03/11 07:32:19 DEBUG : Waiting for deletions to finish 2025/03/11 07:32:19 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pefewaw2dupe'", Local "Local file system at /tmp/rclone22493455", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pefewaw2dupe'", Local "Local file system at /tmp/rclone22493455", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pefewaw2dupe'", Local "Local file system at /tmp/rclone22493455", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pefewaw2dupe'", Local "Local file system at /tmp/rclone22493455", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pefewaw2dupe'", Local "Local file system at /tmp/rclone22493455", Modify Window "1ms" 2025/03/11 07:32:21 DEBUG : khf2vlblvnbf9ftevqm0htmss73hj1j5a7q328e4ohrgs7e2loe0: Rmdir: contains trashed file: "n01jpl9202nn9ec1rb75h0f1c4" 2025/03/11 07:32:22 DEBUG : kmf11jujl9uha3tjganvgpkn45bu778hb5vb5riug1c26b38k7sg: Rmdir: contains trashed file: "i0t74httmdlljg425j6tg570d8" --- PASS: TestSyncOverlapWithFilter (32.26s) === RUN TestSyncCompareDest run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pefewaw2dupe'", Local "Local file system at /tmp/rclone22493455", Modify Window "1ms" 2025/03/11 07:32:32 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-pefewaw2dupe/dst" 2025/03/11 07:32:32 DEBUG : Creating backend with remote "TestDrive:crypt/ksagmlv3rj5m8b0msrmbqotspumdk55608q89rcqpeo8k9oluq3g/31u3jie661vd5p8j7rtc3hgbh0" 2025/03/11 07:32:33 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-pefewaw2dupe/CompareDest" 2025/03/11 07:32:33 DEBUG : Creating backend with remote "TestDrive:crypt/ksagmlv3rj5m8b0msrmbqotspumdk55608q89rcqpeo8k9oluq3g/gveqi14airsml4bgu7krj116o8" 2025/03/11 07:32:35 DEBUG : one: Need to transfer - File not found at Destination 2025/03/11 07:32:35 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pefewaw2dupe/dst': Waiting for checks to finish 2025/03/11 07:32:35 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pefewaw2dupe/dst': Waiting for transfers to finish 2025/03/11 07:32:37 DEBUG : one: md5 = 734faac51b3bc36a5c917335202a09f0 OK 2025/03/11 07:32:37 INFO : one: Copied (new) 2025/03/11 07:32:37 DEBUG : Waiting for deletions to finish 2025/03/11 07:32:38 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pefewaw2dupe/dst': Waiting for checks to finish 2025/03/11 07:32:38 DEBUG : one: Sizes differ (src 5 vs dst 3) 2025/03/11 07:32:39 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pefewaw2dupe/dst': Waiting for transfers to finish 2025/03/11 07:32:40 DEBUG : one: md5 = 5a843771b8936eda94193ee6b3716be0 OK 2025/03/11 07:32:40 INFO : one: Copied (replaced existing) 2025/03/11 07:32:40 DEBUG : Waiting for deletions to finish 2025/03/11 07:32:42 DEBUG : dst/one: md5 = dbdf3a2af90dce6824c53a346810a5fb OK 2025/03/11 07:32:44 DEBUG : CompareDest/one: md5 = 46b7b3b13a49fce37d255f0f1f83bd8c OK 2025/03/11 07:32:45 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pefewaw2dupe/dst': Waiting for checks to finish 2025/03/11 07:32:45 DEBUG : one: Sizes differ (src 5 vs dst 3) 2025/03/11 07:32:45 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/03/11 07:32:45 DEBUG : one: Destination found in --compare-dest, skipping 2025/03/11 07:32:45 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pefewaw2dupe/dst': Waiting for transfers to finish 2025/03/11 07:32:45 DEBUG : Waiting for deletions to finish 2025/03/11 07:32:45 INFO : There was nothing to transfer 2025/03/11 07:32:47 DEBUG : CompareDest/two: md5 = 5781987af791a6d190dc7a6fd767a22c OK 2025/03/11 07:32:48 DEBUG : two: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/03/11 07:32:48 DEBUG : two: Destination found in --compare-dest, skipping 2025/03/11 07:32:48 DEBUG : one: Sizes differ (src 5 vs dst 3) 2025/03/11 07:32:48 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pefewaw2dupe/dst': Waiting for checks to finish 2025/03/11 07:32:49 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/03/11 07:32:49 DEBUG : one: Destination found in --compare-dest, skipping 2025/03/11 07:32:49 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pefewaw2dupe/dst': Waiting for transfers to finish 2025/03/11 07:32:49 DEBUG : Waiting for deletions to finish 2025/03/11 07:32:49 INFO : There was nothing to transfer 2025/03/11 07:32:50 DEBUG : two: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/03/11 07:32:50 DEBUG : two: Destination found in --compare-dest, skipping 2025/03/11 07:32:50 DEBUG : one: Sizes differ (src 5 vs dst 3) 2025/03/11 07:32:50 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pefewaw2dupe/dst': Waiting for checks to finish 2025/03/11 07:32:50 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/03/11 07:32:50 DEBUG : one: Destination found in --compare-dest, skipping 2025/03/11 07:32:50 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pefewaw2dupe/dst': Waiting for transfers to finish 2025/03/11 07:32:50 DEBUG : Waiting for deletions to finish 2025/03/11 07:32:50 INFO : There was nothing to transfer sync_test.go:2175: No hash on uploaded file so skipping compare timestamp test 2025/03/11 07:32:51 DEBUG : two: Sizes differ (src 5 vs dst 3) 2025/03/11 07:32:51 DEBUG : two: Need to transfer - File not found at Destination 2025/03/11 07:32:51 DEBUG : one: Sizes differ (src 5 vs dst 3) 2025/03/11 07:32:51 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pefewaw2dupe/dst': Waiting for checks to finish 2025/03/11 07:32:52 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/03/11 07:32:52 DEBUG : one: Destination found in --compare-dest, skipping 2025/03/11 07:32:52 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pefewaw2dupe/dst': Waiting for transfers to finish 2025/03/11 07:32:53 DEBUG : two: md5 = 46e0008a28b81153bc2bf46116222e7f OK 2025/03/11 07:32:53 INFO : two: Copied (new) 2025/03/11 07:32:53 DEBUG : Waiting for deletions to finish 2025/03/11 07:32:56 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k" 2025/03/11 07:32:56 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" 2025/03/11 07:32:57 DEBUG : gveqi14airsml4bgu7krj116o8: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" 2025/03/11 07:32:57 DEBUG : gveqi14airsml4bgu7krj116o8: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k" --- PASS: TestSyncCompareDest (25.85s) === RUN TestSyncMultipleCompareDest run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pefewaw2dupe'", Local "Local file system at /tmp/rclone22493455", Modify Window "1ms" 2025/03/11 07:33:00 DEBUG : pre-dest1/1: md5 = fa67bca96e757c9bc3b163ae6f72dc28 OK 2025/03/11 07:33:02 DEBUG : pre-dest2/2: md5 = 127dd6b31d2f35517ddc208413e622b0 OK 2025/03/11 07:33:02 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-pefewaw2dupe/dest" 2025/03/11 07:33:02 DEBUG : Config file has changed externally - reloading 2025/03/11 07:33:02 DEBUG : Creating backend with remote "TestDrive:crypt/ksagmlv3rj5m8b0msrmbqotspumdk55608q89rcqpeo8k9oluq3g/rg03c1jvnehrrc617i0lnqjddc" 2025/03/11 07:33:04 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-pefewaw2dupe/pre-dest1" 2025/03/11 07:33:04 DEBUG : Creating backend with remote "TestDrive:crypt/ksagmlv3rj5m8b0msrmbqotspumdk55608q89rcqpeo8k9oluq3g/bbnblvh6k061ssopqrp18kd7gc" 2025/03/11 07:33:05 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-pefewaw2dupe/pre-dest2" 2025/03/11 07:33:05 DEBUG : Creating backend with remote "TestDrive:crypt/ksagmlv3rj5m8b0msrmbqotspumdk55608q89rcqpeo8k9oluq3g/dgicm1h6b5ejvlltm8eeif0bnk" 2025/03/11 07:33:06 DEBUG : 1: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/03/11 07:33:06 DEBUG : 1: Destination found in --compare-dest, skipping 2025/03/11 07:33:07 DEBUG : 2: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/03/11 07:33:07 DEBUG : 2: Destination found in --compare-dest, skipping 2025/03/11 07:33:07 DEBUG : 3: Need to transfer - File not found at Destination 2025/03/11 07:33:07 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pefewaw2dupe/dest': Waiting for checks to finish 2025/03/11 07:33:07 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pefewaw2dupe/dest': Waiting for transfers to finish 2025/03/11 07:33:09 DEBUG : 3: md5 = 2168133042d24a1467a525b37ecc7ed2 OK 2025/03/11 07:33:09 INFO : 3: Copied (new) 2025/03/11 07:33:09 DEBUG : Waiting for deletions to finish 2025/03/11 07:33:12 DEBUG : dgicm1h6b5ejvlltm8eeif0bnk: Rmdir: contains trashed file: "1ghu8geql9vrl726n32nrf65bc" 2025/03/11 07:33:13 DEBUG : bbnblvh6k061ssopqrp18kd7gc: Rmdir: contains trashed file: "skbfko3oil7es0lj68ob574sro" 2025/03/11 07:33:13 DEBUG : rg03c1jvnehrrc617i0lnqjddc: Rmdir: contains trashed file: "g072p7hmjchlnj0gibe64c1epg" --- PASS: TestSyncMultipleCompareDest (16.73s) === RUN TestSyncCopyDest run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pefewaw2dupe'", Local "Local file system at /tmp/rclone22493455", Modify Window "1ms" 2025/03/11 07:33:14 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-pefewaw2dupe/dst" 2025/03/11 07:33:14 DEBUG : Creating backend with remote "TestDrive:crypt/ksagmlv3rj5m8b0msrmbqotspumdk55608q89rcqpeo8k9oluq3g/31u3jie661vd5p8j7rtc3hgbh0" 2025/03/11 07:33:16 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-pefewaw2dupe/CopyDest" 2025/03/11 07:33:16 DEBUG : Creating backend with remote "TestDrive:crypt/ksagmlv3rj5m8b0msrmbqotspumdk55608q89rcqpeo8k9oluq3g/d09o6po3f7bm6ce32vdgs8h9ls" 2025/03/11 07:33:18 DEBUG : one: Need to transfer - File not found at Destination 2025/03/11 07:33:18 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pefewaw2dupe/dst': Waiting for checks to finish 2025/03/11 07:33:18 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pefewaw2dupe/dst': Waiting for transfers to finish 2025/03/11 07:33:20 DEBUG : one: md5 = cc15f22c7fc48917908361ab17fafe19 OK 2025/03/11 07:33:20 INFO : one: Copied (new) 2025/03/11 07:33:20 DEBUG : Waiting for deletions to finish 2025/03/11 07:33:21 DEBUG : one: Sizes differ (src 5 vs dst 3) 2025/03/11 07:33:21 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pefewaw2dupe/dst': Waiting for checks to finish 2025/03/11 07:33:21 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pefewaw2dupe/dst': Waiting for transfers to finish 2025/03/11 07:33:23 DEBUG : one: md5 = c36efbe207a2da2cd0dd2852d35ba99f OK 2025/03/11 07:33:23 INFO : one: Copied (replaced existing) 2025/03/11 07:33:23 DEBUG : Waiting for deletions to finish 2025/03/11 07:33:24 DEBUG : dst/one: md5 = d73e8b72a17d5599c9457f91b6833797 OK 2025/03/11 07:33:27 DEBUG : CopyDest/one: md5 = 865a5292200a5f82d2ce9c270dc537e7 OK 2025/03/11 07:33:28 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-pefewaw2dupe/BackupDir" 2025/03/11 07:33:28 DEBUG : Creating backend with remote "TestDrive:crypt/ksagmlv3rj5m8b0msrmbqotspumdk55608q89rcqpeo8k9oluq3g/s6dbk3lfi7c9kfvo6j7bla9m0g" 2025/03/11 07:33:29 DEBUG : one: Sizes differ (src 5 vs dst 3) 2025/03/11 07:33:29 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pefewaw2dupe/dst': Waiting for checks to finish 2025/03/11 07:33:30 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/03/11 07:33:30 DEBUG : one: Sizes differ (src 5 vs dst 3) 2025/03/11 07:33:32 INFO : one: Moved (server-side) 2025/03/11 07:33:33 INFO : one: Copied (server-side copy) 2025/03/11 07:33:33 DEBUG : one: Destination found in --copy-dest, using server-side copy 2025/03/11 07:33:33 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pefewaw2dupe/dst': Waiting for transfers to finish 2025/03/11 07:33:33 DEBUG : Waiting for deletions to finish 2025/03/11 07:33:35 DEBUG : CopyDest/two: md5 = 38b4ed705fdafd14afd5f4cbd2bbc424 OK 2025/03/11 07:33:36 DEBUG : two: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/03/11 07:33:37 INFO : two: Copied (server-side copy) 2025/03/11 07:33:37 DEBUG : two: Destination found in --copy-dest, using server-side copy 2025/03/11 07:33:37 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/03/11 07:33:37 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pefewaw2dupe/dst': Waiting for checks to finish 2025/03/11 07:33:37 DEBUG : one: Unchanged skipping 2025/03/11 07:33:37 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pefewaw2dupe/dst': Waiting for transfers to finish 2025/03/11 07:33:37 DEBUG : Waiting for deletions to finish 2025/03/11 07:33:37 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/03/11 07:33:37 DEBUG : two: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/03/11 07:33:37 DEBUG : one: Unchanged skipping 2025/03/11 07:33:37 DEBUG : two: Unchanged skipping 2025/03/11 07:33:37 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pefewaw2dupe/dst': Waiting for checks to finish 2025/03/11 07:33:37 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pefewaw2dupe/dst': Waiting for transfers to finish 2025/03/11 07:33:37 DEBUG : Waiting for deletions to finish 2025/03/11 07:33:37 INFO : There was nothing to transfer 2025/03/11 07:33:39 DEBUG : CopyDest/three: md5 = 06a091382b4a057a977b411141468d8a OK 2025/03/11 07:33:40 DEBUG : three: Sizes differ (src 7 vs dst 5) 2025/03/11 07:33:40 DEBUG : three: Destination not found in --copy-dest 2025/03/11 07:33:40 DEBUG : three: Need to transfer - File not found at Destination 2025/03/11 07:33:40 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/03/11 07:33:40 DEBUG : one: Unchanged skipping 2025/03/11 07:33:40 DEBUG : two: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/03/11 07:33:40 DEBUG : two: Unchanged skipping 2025/03/11 07:33:40 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pefewaw2dupe/dst': Waiting for checks to finish 2025/03/11 07:33:40 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pefewaw2dupe/dst': Waiting for transfers to finish 2025/03/11 07:33:42 DEBUG : three: md5 = c214110afad22b09d0d93aec06a0724d OK 2025/03/11 07:33:42 INFO : three: Copied (new) 2025/03/11 07:33:42 DEBUG : Waiting for deletions to finish 2025/03/11 07:33:46 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "b6jdmn2b1adrhc8vikh7edr9os" 2025/03/11 07:33:46 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" 2025/03/11 07:33:46 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k" 2025/03/11 07:33:47 DEBUG : d09o6po3f7bm6ce32vdgs8h9ls: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k" 2025/03/11 07:33:47 DEBUG : d09o6po3f7bm6ce32vdgs8h9ls: Rmdir: contains trashed file: "b6jdmn2b1adrhc8vikh7edr9os" 2025/03/11 07:33:47 DEBUG : d09o6po3f7bm6ce32vdgs8h9ls: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" 2025/03/11 07:33:48 DEBUG : s6dbk3lfi7c9kfvo6j7bla9m0g: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" --- PASS: TestSyncCopyDest (34.30s) === RUN TestSyncBackupDir run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pefewaw2dupe'", Local "Local file system at /tmp/rclone22493455", Modify Window "1ms" 2025/03/11 07:33:51 DEBUG : dst/one: md5 = bdb619ead7311cc659f89860ec0c3609 OK 2025/03/11 07:33:52 DEBUG : dst/two: md5 = 6b08376951539f635c95c5d1cb1fcfa3 OK 2025/03/11 07:33:54 DEBUG : dst/three.txt: md5 = 39da29fbab9b12b7ff85c00956e73c86 OK 2025/03/11 07:33:54 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-pefewaw2dupe/dst" 2025/03/11 07:33:54 DEBUG : Config file has changed externally - reloading 2025/03/11 07:33:55 DEBUG : Creating backend with remote "TestDrive:crypt/ksagmlv3rj5m8b0msrmbqotspumdk55608q89rcqpeo8k9oluq3g/31u3jie661vd5p8j7rtc3hgbh0" 2025/03/11 07:33:55 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-pefewaw2dupe/backup" 2025/03/11 07:33:55 DEBUG : Creating backend with remote "TestDrive:crypt/ksagmlv3rj5m8b0msrmbqotspumdk55608q89rcqpeo8k9oluq3g/1nrff024r7pq65ecp72fc28jb0" 2025/03/11 07:33:57 DEBUG : one: Sizes differ (src 4 vs dst 3) 2025/03/11 07:33:57 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/03/11 07:33:57 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pefewaw2dupe/dst': Waiting for checks to finish 2025/03/11 07:33:57 DEBUG : two: Unchanged skipping 2025/03/11 07:33:59 INFO : one: Moved (server-side) 2025/03/11 07:33:59 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pefewaw2dupe/dst': Waiting for transfers to finish 2025/03/11 07:34:00 DEBUG : one: md5 = c3b4f54cb6da2cbc68a9cba7cfabea33 OK 2025/03/11 07:34:00 INFO : one: Copied (new) 2025/03/11 07:34:00 DEBUG : Waiting for deletions to finish 2025/03/11 07:34:01 INFO : three.txt: Moved (server-side) 2025/03/11 07:34:01 INFO : three.txt: Moved into backup dir 2025/03/11 07:34:03 DEBUG : dst/three.txt: md5 = 93044952e315548da917f3f84ebf8544 OK 2025/03/11 07:34:04 DEBUG : one: Sizes differ (src 5 vs dst 4) 2025/03/11 07:34:04 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/03/11 07:34:04 DEBUG : two: Unchanged skipping 2025/03/11 07:34:04 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pefewaw2dupe/dst': Waiting for checks to finish 2025/03/11 07:34:05 INFO : one: Deleted 2025/03/11 07:34:05 INFO : one: Moved (server-side) 2025/03/11 07:34:05 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pefewaw2dupe/dst': Waiting for transfers to finish 2025/03/11 07:34:07 DEBUG : one: md5 = aa8ff757bb74fa3568d23e19f920f681 OK 2025/03/11 07:34:07 INFO : one: Copied (new) 2025/03/11 07:34:07 DEBUG : Waiting for deletions to finish 2025/03/11 07:34:07 INFO : three.txt: Deleted 2025/03/11 07:34:08 INFO : three.txt: Moved (server-side) 2025/03/11 07:34:08 INFO : three.txt: Moved into backup dir 2025/03/11 07:34:11 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" 2025/03/11 07:34:11 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k" 2025/03/11 07:34:12 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" 2025/03/11 07:34:12 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "tr2hj63d80ftlmvm6a952snjcc" 2025/03/11 07:34:12 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "tr2hj63d80ftlmvm6a952snjcc" 2025/03/11 07:34:12 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" --- PASS: TestSyncBackupDir (24.35s) === RUN TestSyncBackupDirWithSuffix run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pefewaw2dupe'", Local "Local file system at /tmp/rclone22493455", Modify Window "1ms" 2025/03/11 07:34:15 DEBUG : dst/one: md5 = 8ffab544054269a3ac00b6b0b7fac39c OK 2025/03/11 07:34:16 DEBUG : dst/two: md5 = 6be2318397f5e7252e7a8cd39c3c3ae4 OK 2025/03/11 07:34:18 DEBUG : dst/three.txt: md5 = c4ae64bbfef98734dc85fad934b8ba0c OK 2025/03/11 07:34:18 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-pefewaw2dupe/dst" 2025/03/11 07:34:18 DEBUG : Creating backend with remote "TestDrive:crypt/ksagmlv3rj5m8b0msrmbqotspumdk55608q89rcqpeo8k9oluq3g/31u3jie661vd5p8j7rtc3hgbh0" 2025/03/11 07:34:19 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-pefewaw2dupe/backup" 2025/03/11 07:34:19 DEBUG : Creating backend with remote "TestDrive:crypt/ksagmlv3rj5m8b0msrmbqotspumdk55608q89rcqpeo8k9oluq3g/1nrff024r7pq65ecp72fc28jb0" 2025/03/11 07:34:21 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/03/11 07:34:21 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pefewaw2dupe/dst': Waiting for checks to finish 2025/03/11 07:34:21 DEBUG : two: Unchanged skipping 2025/03/11 07:34:21 DEBUG : one: Sizes differ (src 4 vs dst 3) 2025/03/11 07:34:22 INFO : one: Moved (server-side) to: one.bak 2025/03/11 07:34:22 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pefewaw2dupe/dst': Waiting for transfers to finish 2025/03/11 07:34:24 DEBUG : one: md5 = 264ae589d1e542418d48ee30b10d1624 OK 2025/03/11 07:34:24 INFO : one: Copied (new) 2025/03/11 07:34:24 DEBUG : Waiting for deletions to finish 2025/03/11 07:34:25 INFO : three.txt: Moved (server-side) to: three.txt.bak 2025/03/11 07:34:25 INFO : three.txt: Moved into backup dir 2025/03/11 07:34:27 DEBUG : dst/three.txt: md5 = b4997ec13172907c002e10ad31c073e1 OK 2025/03/11 07:34:27 DEBUG : one: Sizes differ (src 5 vs dst 4) 2025/03/11 07:34:27 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pefewaw2dupe/dst': Waiting for checks to finish 2025/03/11 07:34:27 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/03/11 07:34:27 DEBUG : two: Unchanged skipping 2025/03/11 07:34:28 INFO : one.bak: Deleted 2025/03/11 07:34:29 INFO : one: Moved (server-side) to: one.bak 2025/03/11 07:34:29 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pefewaw2dupe/dst': Waiting for transfers to finish 2025/03/11 07:34:30 DEBUG : one: md5 = 8fc82ce22cc0f38ef59a70c0f51b0912 OK 2025/03/11 07:34:30 INFO : one: Copied (new) 2025/03/11 07:34:30 DEBUG : Waiting for deletions to finish 2025/03/11 07:34:31 INFO : three.txt.bak: Deleted 2025/03/11 07:34:31 INFO : three.txt: Moved (server-side) to: three.txt.bak 2025/03/11 07:34:31 INFO : three.txt: Moved into backup dir 2025/03/11 07:34:35 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" 2025/03/11 07:34:35 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k" 2025/03/11 07:34:35 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "qltcak2uaegtmcoa8vijdppbp8" 2025/03/11 07:34:35 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "sk91qgsqfn0r271r2ehsaoc20c" 2025/03/11 07:34:35 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "sk91qgsqfn0r271r2ehsaoc20c" 2025/03/11 07:34:35 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "qltcak2uaegtmcoa8vijdppbp8" --- PASS: TestSyncBackupDirWithSuffix (23.31s) === RUN TestSyncBackupDirWithSuffixKeepExtension run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pefewaw2dupe'", Local "Local file system at /tmp/rclone22493455", Modify Window "1ms" 2025/03/11 07:34:38 DEBUG : dst/one: md5 = c992185f4f8b14897fe078b09be33beb OK 2025/03/11 07:34:40 DEBUG : dst/two: md5 = e9db530e9ac31758bf7553edad87400b OK 2025/03/11 07:34:41 DEBUG : dst/three.txt: md5 = 167af0b06c428797b132997684ed24df OK 2025/03/11 07:34:42 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-pefewaw2dupe/dst" 2025/03/11 07:34:42 DEBUG : Creating backend with remote "TestDrive:crypt/ksagmlv3rj5m8b0msrmbqotspumdk55608q89rcqpeo8k9oluq3g/31u3jie661vd5p8j7rtc3hgbh0" 2025/03/11 07:34:42 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-pefewaw2dupe/backup" 2025/03/11 07:34:42 DEBUG : Creating backend with remote "TestDrive:crypt/ksagmlv3rj5m8b0msrmbqotspumdk55608q89rcqpeo8k9oluq3g/1nrff024r7pq65ecp72fc28jb0" 2025/03/11 07:34:44 DEBUG : one: Sizes differ (src 4 vs dst 3) 2025/03/11 07:34:44 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/03/11 07:34:44 DEBUG : two: Unchanged skipping 2025/03/11 07:34:44 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pefewaw2dupe/dst': Waiting for checks to finish 2025/03/11 07:34:46 INFO : one: Moved (server-side) to: one-2019-01-01 2025/03/11 07:34:46 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pefewaw2dupe/dst': Waiting for transfers to finish 2025/03/11 07:34:47 DEBUG : one: md5 = ecb09a2b766ccb1d156af3a7a807c30a OK 2025/03/11 07:34:47 INFO : one: Copied (new) 2025/03/11 07:34:47 DEBUG : Waiting for deletions to finish 2025/03/11 07:34:48 INFO : three.txt: Moved (server-side) to: three-2019-01-01.txt 2025/03/11 07:34:48 INFO : three.txt: Moved into backup dir 2025/03/11 07:34:50 DEBUG : dst/three.txt: md5 = 0b4388be7c7d540fdce1ee4da3ee4a64 OK 2025/03/11 07:34:51 DEBUG : one: Sizes differ (src 5 vs dst 4) 2025/03/11 07:34:51 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/03/11 07:34:51 DEBUG : two: Unchanged skipping 2025/03/11 07:34:51 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pefewaw2dupe/dst': Waiting for checks to finish 2025/03/11 07:34:52 INFO : one-2019-01-01: Deleted 2025/03/11 07:34:52 INFO : one: Moved (server-side) to: one-2019-01-01 2025/03/11 07:34:52 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pefewaw2dupe/dst': Waiting for transfers to finish 2025/03/11 07:34:54 DEBUG : one: md5 = 881df258a1d81bd9189a38b1b0c7efc6 OK 2025/03/11 07:34:54 INFO : one: Copied (new) 2025/03/11 07:34:54 DEBUG : Waiting for deletions to finish 2025/03/11 07:34:55 INFO : three-2019-01-01.txt: Deleted 2025/03/11 07:34:55 INFO : three.txt: Moved (server-side) to: three-2019-01-01.txt 2025/03/11 07:34:55 INFO : three.txt: Moved into backup dir 2025/03/11 07:34:58 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" 2025/03/11 07:34:58 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k" 2025/03/11 07:34:59 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "qtq2f6qq4lgpsmj88vb7147qje3prudmtfdtr2342fth58vo9a50" 2025/03/11 07:34:59 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "jcjl1bv3ep0v8kt35lqql1co90" 2025/03/11 07:34:59 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "jcjl1bv3ep0v8kt35lqql1co90" 2025/03/11 07:34:59 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "qtq2f6qq4lgpsmj88vb7147qje3prudmtfdtr2342fth58vo9a50" --- PASS: TestSyncBackupDirWithSuffixKeepExtension (23.73s) === RUN TestSyncBackupDirSuffixOnly run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pefewaw2dupe'", Local "Local file system at /tmp/rclone22493455", Modify Window "1ms" 2025/03/11 07:35:02 DEBUG : dst/one: md5 = 456cd8d190555cd427e0449663917448 OK 2025/03/11 07:35:04 DEBUG : dst/two: md5 = b63b870a6ae25e501ceb573b901d6998 OK 2025/03/11 07:35:05 DEBUG : dst/three.txt: md5 = 88e10c475abaf42e3bdd4ae459b4dfbc OK 2025/03/11 07:35:06 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-pefewaw2dupe/dst" 2025/03/11 07:35:06 DEBUG : Creating backend with remote "TestDrive:crypt/ksagmlv3rj5m8b0msrmbqotspumdk55608q89rcqpeo8k9oluq3g/31u3jie661vd5p8j7rtc3hgbh0" 2025/03/11 07:35:07 DEBUG : one: Sizes differ (src 4 vs dst 3) 2025/03/11 07:35:07 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pefewaw2dupe/dst': Waiting for checks to finish 2025/03/11 07:35:07 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/03/11 07:35:07 DEBUG : two: Unchanged skipping 2025/03/11 07:35:07 INFO : one: Moved (server-side) to: one.bak 2025/03/11 07:35:07 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pefewaw2dupe/dst': Waiting for transfers to finish 2025/03/11 07:35:09 DEBUG : one: md5 = 1051842774200ae0fde4af988bb3f3e5 OK 2025/03/11 07:35:09 INFO : one: Copied (new) 2025/03/11 07:35:09 DEBUG : Waiting for deletions to finish 2025/03/11 07:35:10 INFO : three.txt: Moved (server-side) to: three.txt.bak 2025/03/11 07:35:10 INFO : three.txt: Moved into backup dir 2025/03/11 07:35:11 DEBUG : dst/three.txt: md5 = c99fcc28c68e5054985e089e64876dea OK 2025/03/11 07:35:12 DEBUG : one.bak: Excluded (Path Filter) 2025/03/11 07:35:12 DEBUG : three.txt.bak: Excluded (Path Filter) 2025/03/11 07:35:12 DEBUG : one: Sizes differ (src 5 vs dst 4) 2025/03/11 07:35:12 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/03/11 07:35:12 DEBUG : two: Unchanged skipping 2025/03/11 07:35:12 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pefewaw2dupe/dst': Waiting for checks to finish 2025/03/11 07:35:13 INFO : one.bak: Deleted 2025/03/11 07:35:14 INFO : one: Moved (server-side) to: one.bak 2025/03/11 07:35:14 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pefewaw2dupe/dst': Waiting for transfers to finish 2025/03/11 07:35:15 DEBUG : one: md5 = 6893684d8a51a4448609fe2225d54846 OK 2025/03/11 07:35:15 INFO : one: Copied (new) 2025/03/11 07:35:15 DEBUG : Waiting for deletions to finish 2025/03/11 07:35:16 INFO : three.txt.bak: Deleted 2025/03/11 07:35:16 INFO : three.txt: Moved (server-side) to: three.txt.bak 2025/03/11 07:35:16 INFO : three.txt: Moved into backup dir 2025/03/11 07:35:19 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" 2025/03/11 07:35:19 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "sk91qgsqfn0r271r2ehsaoc20c" 2025/03/11 07:35:19 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "qltcak2uaegtmcoa8vijdppbp8" 2025/03/11 07:35:19 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k" 2025/03/11 07:35:19 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "qltcak2uaegtmcoa8vijdppbp8" 2025/03/11 07:35:19 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "sk91qgsqfn0r271r2ehsaoc20c" --- PASS: TestSyncBackupDirSuffixOnly (20.14s) === RUN TestSyncSuffix run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pefewaw2dupe'", Local "Local file system at /tmp/rclone22493455", Modify Window "1ms" 2025/03/11 07:35:22 DEBUG : dst/one: md5 = 1c099c15f1ccf6eb587871a5b747e7c2 OK 2025/03/11 07:35:24 DEBUG : dst/two: md5 = 17bef66f8bd912986bd85e2166009832 OK 2025/03/11 07:35:25 DEBUG : dst/three.txt: md5 = 66ad5c4a33580ca5818ed190ae9a6db5 OK 2025/03/11 07:35:26 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-pefewaw2dupe/dst" 2025/03/11 07:35:26 DEBUG : Creating backend with remote "TestDrive:crypt/ksagmlv3rj5m8b0msrmbqotspumdk55608q89rcqpeo8k9oluq3g/31u3jie661vd5p8j7rtc3hgbh0" 2025/03/11 07:35:27 DEBUG : one: Sizes differ (src 4 vs dst 3) 2025/03/11 07:35:28 INFO : one: Moved (server-side) to: one.bak 2025/03/11 07:35:29 DEBUG : one: md5 = 4bfa948112b4609224aa52c31d9eb417 OK 2025/03/11 07:35:29 INFO : one: Copied (new) 2025/03/11 07:35:29 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/03/11 07:35:29 DEBUG : two: Unchanged skipping 2025/03/11 07:35:30 DEBUG : three.txt: Sizes differ (src 6 vs dst 5) 2025/03/11 07:35:30 INFO : three.txt: Moved (server-side) to: three.txt.bak 2025/03/11 07:35:32 DEBUG : three.txt: md5 = c9f78290234e18510789ca70d3967ca2 OK 2025/03/11 07:35:32 INFO : three.txt: Copied (new) 2025/03/11 07:35:33 DEBUG : one: Sizes differ (src 5 vs dst 4) 2025/03/11 07:35:34 INFO : one.bak: Deleted 2025/03/11 07:35:34 INFO : one: Moved (server-side) to: one.bak 2025/03/11 07:35:36 DEBUG : one: md5 = 2af304ea912f5b0a32bbfa590ba493b8 OK 2025/03/11 07:35:36 INFO : one: Copied (new) 2025/03/11 07:35:36 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/03/11 07:35:36 DEBUG : two: Unchanged skipping 2025/03/11 07:35:36 DEBUG : three.txt: Sizes differ (src 19 vs dst 6) 2025/03/11 07:35:37 INFO : three.txt.bak: Deleted 2025/03/11 07:35:37 INFO : three.txt: Moved (server-side) to: three.txt.bak 2025/03/11 07:35:39 DEBUG : three.txt: md5 = 6e844bb0fbf3fe25cd78db87b45261b5 OK 2025/03/11 07:35:39 INFO : three.txt: Copied (new) 2025/03/11 07:36:24 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" 2025/03/11 07:36:24 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "tr2hj63d80ftlmvm6a952snjcc" 2025/03/11 07:36:24 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "qltcak2uaegtmcoa8vijdppbp8" 2025/03/11 07:36:24 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "sk91qgsqfn0r271r2ehsaoc20c" 2025/03/11 07:36:24 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k" 2025/03/11 07:36:24 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "qltcak2uaegtmcoa8vijdppbp8" 2025/03/11 07:36:24 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "sk91qgsqfn0r271r2ehsaoc20c" --- PASS: TestSyncSuffix (64.61s) === RUN TestSyncSuffixKeepExtension run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pefewaw2dupe'", Local "Local file system at /tmp/rclone22493455", Modify Window "1ms" 2025/03/11 07:36:27 DEBUG : dst/one: md5 = 3241439a73f452d1323129c73de8f537 OK 2025/03/11 07:36:28 DEBUG : dst/two: md5 = 6dd9a8cf42659a3606ca094e63887a69 OK 2025/03/11 07:36:30 DEBUG : dst/three.txt: md5 = fa279fe8108308e5fa317f62f30f7bdd OK 2025/03/11 07:36:30 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-pefewaw2dupe/dst" 2025/03/11 07:36:31 DEBUG : Creating backend with remote "TestDrive:crypt/ksagmlv3rj5m8b0msrmbqotspumdk55608q89rcqpeo8k9oluq3g/31u3jie661vd5p8j7rtc3hgbh0" 2025/03/11 07:36:31 DEBUG : one: Sizes differ (src 4 vs dst 3) 2025/03/11 07:36:32 INFO : one: Moved (server-side) to: one-2019-01-01 2025/03/11 07:36:34 DEBUG : one: md5 = 466b5c2918803ad9885fcd60e31166a5 OK 2025/03/11 07:36:34 INFO : one: Copied (new) 2025/03/11 07:36:34 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/03/11 07:36:34 DEBUG : two: Unchanged skipping 2025/03/11 07:36:34 DEBUG : three.txt: Sizes differ (src 6 vs dst 5) 2025/03/11 07:36:35 INFO : three.txt: Moved (server-side) to: three-2019-01-01.txt 2025/03/11 07:36:37 DEBUG : three.txt: md5 = 68c841a9589c58281b1f769a2b1b15a7 OK 2025/03/11 07:36:37 INFO : three.txt: Copied (new) 2025/03/11 07:36:38 DEBUG : one: Sizes differ (src 5 vs dst 4) 2025/03/11 07:36:38 INFO : one-2019-01-01: Deleted 2025/03/11 07:36:39 INFO : one: Moved (server-side) to: one-2019-01-01 2025/03/11 07:36:42 DEBUG : one: md5 = 9cec50549a97fed692b40e19504dbdd1 OK 2025/03/11 07:36:42 INFO : one: Copied (new) 2025/03/11 07:36:43 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/03/11 07:36:43 DEBUG : two: Unchanged skipping 2025/03/11 07:36:43 DEBUG : three.txt: Sizes differ (src 19 vs dst 6) 2025/03/11 07:36:44 INFO : three-2019-01-01.txt: Deleted 2025/03/11 07:36:44 INFO : three.txt: Moved (server-side) to: three-2019-01-01.txt 2025/03/11 07:36:46 DEBUG : three.txt: md5 = d1eb3a4e44d375fdbeaa499721c734a7 OK 2025/03/11 07:36:46 INFO : three.txt: Copied (new) 2025/03/11 07:36:49 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "tr2hj63d80ftlmvm6a952snjcc" 2025/03/11 07:36:49 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" 2025/03/11 07:36:49 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "jcjl1bv3ep0v8kt35lqql1co90" 2025/03/11 07:36:49 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "qtq2f6qq4lgpsmj88vb7147qje3prudmtfdtr2342fth58vo9a50" 2025/03/11 07:36:49 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k" 2025/03/11 07:36:49 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "jcjl1bv3ep0v8kt35lqql1co90" 2025/03/11 07:36:49 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "qtq2f6qq4lgpsmj88vb7147qje3prudmtfdtr2342fth58vo9a50" --- PASS: TestSyncSuffixKeepExtension (25.39s) === RUN TestSyncUTFNorm run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pefewaw2dupe'", Local "Local file system at /tmp/rclone22493455", Modify Window "1ms" 2025/03/11 07:36:51 DEBUG : Testêé: md5 = 44ad1056861ec2406f212eb9a0f803d2 OK 2025/03/11 07:36:52 DEBUG : Testêé: Sizes differ (src 14 vs dst 18) 2025/03/11 07:36:52 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pefewaw2dupe': Waiting for checks to finish 2025/03/11 07:36:52 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pefewaw2dupe': Waiting for transfers to finish 2025/03/11 07:36:53 DEBUG : Testêé: md5 = 0733fb35f356342ef6cfe0ddb63f51d8 OK 2025/03/11 07:36:53 INFO : Testêé: Copied (replaced existing) to: Testêé 2025/03/11 07:36:53 DEBUG : Waiting for deletions to finish --- PASS: TestSyncUTFNorm (4.34s) === RUN TestSyncImmutable run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pefewaw2dupe'", Local "Local file system at /tmp/rclone22493455", Modify Window "1ms" 2025/03/11 07:36:55 DEBUG : existing: Need to transfer - File not found at Destination 2025/03/11 07:36:55 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pefewaw2dupe': Waiting for checks to finish 2025/03/11 07:36:55 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pefewaw2dupe': Waiting for transfers to finish 2025/03/11 07:36:56 DEBUG : existing: md5 = 27c8f6d3c112fb40576bfdce0d92c948 OK 2025/03/11 07:36:56 INFO : existing: Copied (new) 2025/03/11 07:36:56 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pefewaw2dupe'", Local "Local file system at /tmp/rclone22493455", Modify Window "1ms" 2025/03/11 07:36:57 DEBUG : existing: Sizes differ (src 8 vs dst 6) 2025/03/11 07:36:57 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pefewaw2dupe': Waiting for checks to finish 2025/03/11 07:36:57 ERROR : existing: Source and destination exist but do not match: immutable file modified 2025/03/11 07:36:57 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pefewaw2dupe': Waiting for transfers to finish 2025/03/11 07:36:57 ERROR : Encrypted drive 'TestCryptDrive:rclone-test-pefewaw2dupe': not deleting files as there were IO errors 2025/03/11 07:36:57 ERROR : Encrypted drive 'TestCryptDrive:rclone-test-pefewaw2dupe': not deleting directories as there were IO errors run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pefewaw2dupe'", Local "Local file system at /tmp/rclone22493455", Modify Window "1ms" --- PASS: TestSyncImmutable (4.88s) === RUN TestSyncIgnoreCase run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pefewaw2dupe'", Local "Local file system at /tmp/rclone22493455", Modify Window "1ms" 2025/03/11 07:37:00 DEBUG : EXISTING: md5 = 6fed5f0c6f534520501b433611e0d5c8 OK 2025/03/11 07:37:01 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pefewaw2dupe': Waiting for checks to finish 2025/03/11 07:37:01 DEBUG : existing: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/03/11 07:37:01 DEBUG : existing: Unchanged skipping 2025/03/11 07:37:01 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pefewaw2dupe': Waiting for transfers to finish 2025/03/11 07:37:01 DEBUG : Waiting for deletions to finish 2025/03/11 07:37:01 INFO : There was nothing to transfer --- PASS: TestSyncIgnoreCase (3.03s) === RUN TestFixCase run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pefewaw2dupe'", Local "Local file system at /tmp/rclone22493455", Modify Window "1ms" sync_test.go:2635: Skipping test as local or remote are case-sensitive --- SKIP: TestFixCase (0.49s) === RUN TestMaxTransfer === RUN TestMaxTransfer/Hard run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pefewaw2dupe'", Local "Local file system at /tmp/rclone22493455", 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-pefewaw2dupe'", Local "Local file system at /tmp/rclone22493455", 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-pefewaw2dupe'", Local "Local file system at /tmp/rclone22493455", Modify Window "1ms" sync_test.go:2674: This test only runs on local --- PASS: TestMaxTransfer (1.36s) --- SKIP: TestMaxTransfer/Hard (0.48s) --- SKIP: TestMaxTransfer/Soft (0.45s) --- SKIP: TestMaxTransfer/Cautious (0.43s) === RUN TestSyncConcurrentDelete run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pefewaw2dupe'", Local "Local file system at /tmp/rclone22493455", Modify Window "1ms" 2025/03/11 07:37:06 DEBUG : both0: md5 = d21338274da34c80007bc34af04acc79 OK 2025/03/11 07:37:07 DEBUG : only0: md5 = 5915d00c56c5cebc2a1f5a18f7fb3f8f OK 2025/03/11 07:37:08 DEBUG : both1: md5 = 93b4a718d16891edb5f38f150d1b619f OK 2025/03/11 07:37:10 DEBUG : only1: md5 = 457c686b81fc395014b9c9c4a8dc4e57 OK 2025/03/11 07:37:11 DEBUG : both2: md5 = 6dae006458258d990416c1cc59746f58 OK 2025/03/11 07:37:13 DEBUG : only2: md5 = a678dd296cc957a79361b2ed2e652128 OK 2025/03/11 07:37:14 DEBUG : both3: md5 = 8cfc9634fcc8465d4f1799fa6e6709d5 OK 2025/03/11 07:37:15 DEBUG : only3: md5 = 429c27dff24ef2c25b5beec02c8bcdbc OK 2025/03/11 07:37:17 DEBUG : both4: md5 = 971ef5f572c801a02f01b9eea665877b OK 2025/03/11 07:37:18 DEBUG : only4: md5 = 2dc32559deaa253916a296c6e73c5b82 OK 2025/03/11 07:37:20 DEBUG : both5: md5 = 1d066ebc025018b2d600d0ae5a1dbe48 OK 2025/03/11 07:37:21 DEBUG : only5: md5 = 4d29a8496ddd08de45e462f1e373dcaa OK 2025/03/11 07:37:22 DEBUG : both6: md5 = 8e1711e4faa9b2fa52572fe0ebe2a38a OK 2025/03/11 07:37:24 DEBUG : only6: md5 = 8c6d0a65706e693b0babea8b6e6bc5f5 OK 2025/03/11 07:37:25 DEBUG : both7: md5 = f81518eec38e5d03754d19dca42a5d25 OK 2025/03/11 07:37:26 DEBUG : only7: md5 = bc76a40e3fb70f4b9e50a77efeb7ceb9 OK 2025/03/11 07:37:28 DEBUG : both8: md5 = 2a437f70b8eeaad38391dba48b6c8dd0 OK 2025/03/11 07:37:29 DEBUG : only8: md5 = 7b63f52a981ed18077d2ec24b5531566 OK 2025/03/11 07:37:31 DEBUG : both9: md5 = 02470d6e6619344465e1974128dff052 OK 2025/03/11 07:37:32 DEBUG : only9: md5 = 1d641a643c6fcf9683bb71a3043c2aab OK 2025/03/11 07:37:34 DEBUG : both10: md5 = f899199ef161f4c07efe264a2c07e988 OK 2025/03/11 07:37:35 DEBUG : only10: md5 = 007370ad0212368a70b2954f3b7431a4 OK 2025/03/11 07:37:37 DEBUG : both11: md5 = aa558b3ddade3305c13d26f92314e04a OK 2025/03/11 07:37:38 DEBUG : only11: md5 = 59f51db73137d710fafe0f8e5c250920 OK 2025/03/11 07:37:39 DEBUG : both12: md5 = 409ec0c8610cb86160d4776521521a51 OK 2025/03/11 07:37:41 DEBUG : only12: md5 = e9dad30cc809c8378443ba9d7df9fd65 OK 2025/03/11 07:37:42 DEBUG : both13: md5 = 8781008d4d1e57dde49a7d25a75b03fb OK 2025/03/11 07:37:44 DEBUG : only13: md5 = 382e2d0270fe922ac60028e34188d5c1 OK 2025/03/11 07:37:45 DEBUG : both14: md5 = 6e8c4668af687f5c6c2d2e3bc7989fb0 OK 2025/03/11 07:37:46 DEBUG : only14: md5 = 305c3490aee792212871e93588233b72 OK 2025/03/11 07:37:48 DEBUG : both15: md5 = c57b7e683bb3635c27c94b7360b68a45 OK 2025/03/11 07:37:49 DEBUG : only15: md5 = 4b7f9072b489bde642bb2463c13be942 OK 2025/03/11 07:37:51 DEBUG : both16: md5 = b08b8d63d6c48554dc3e78b5b2d5d9d1 OK 2025/03/11 07:37:52 DEBUG : only16: md5 = cb3d58fd33c01cda570aaf886ba8ae16 OK 2025/03/11 07:37:53 DEBUG : both17: md5 = 999ee97188d9fba333bc773f86fc71c5 OK 2025/03/11 07:37:55 DEBUG : only17: md5 = 74417d68516885e6509c21f4adb91691 OK 2025/03/11 07:37:56 DEBUG : both18: md5 = 69562e2e7198633a1bdc0f5726401eb4 OK 2025/03/11 07:37:57 DEBUG : only18: md5 = 121dc0d19847e1ecd6546890a20db2bc OK 2025/03/11 07:37:59 DEBUG : both19: md5 = 6a5f64dd82df0ff877649678ac7fda3a OK 2025/03/11 07:38:00 DEBUG : only19: md5 = cae34221f468271da88e1d65042c1f70 OK 2025/03/11 07:38:01 DEBUG : both0: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/03/11 07:38:01 DEBUG : both11: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/03/11 07:38:01 DEBUG : both10: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/03/11 07:38:01 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pefewaw2dupe': Waiting for checks to finish 2025/03/11 07:38:01 DEBUG : both1: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/03/11 07:38:01 DEBUG : both0: Unchanged skipping 2025/03/11 07:38:01 DEBUG : both12: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/03/11 07:38:01 DEBUG : both12: Unchanged skipping 2025/03/11 07:38:01 DEBUG : both13: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/03/11 07:38:01 DEBUG : both13: Unchanged skipping 2025/03/11 07:38:01 DEBUG : both14: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/03/11 07:38:01 DEBUG : both11: Unchanged skipping 2025/03/11 07:38:01 DEBUG : both15: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/03/11 07:38:01 DEBUG : both15: Unchanged skipping 2025/03/11 07:38:01 DEBUG : both16: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/03/11 07:38:01 DEBUG : both16: Unchanged skipping 2025/03/11 07:38:01 DEBUG : both17: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/03/11 07:38:01 DEBUG : both10: Unchanged skipping 2025/03/11 07:38:01 DEBUG : both18: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/03/11 07:38:01 DEBUG : both18: Unchanged skipping 2025/03/11 07:38:01 DEBUG : both19: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/03/11 07:38:01 DEBUG : both19: Unchanged skipping 2025/03/11 07:38:01 DEBUG : both2: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/03/11 07:38:01 DEBUG : both2: Unchanged skipping 2025/03/11 07:38:01 DEBUG : both3: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/03/11 07:38:01 DEBUG : both3: Unchanged skipping 2025/03/11 07:38:01 DEBUG : both4: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/03/11 07:38:01 DEBUG : both4: Unchanged skipping 2025/03/11 07:38:01 DEBUG : both5: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/03/11 07:38:01 DEBUG : both5: Unchanged skipping 2025/03/11 07:38:01 DEBUG : both6: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/03/11 07:38:01 DEBUG : both6: Unchanged skipping 2025/03/11 07:38:01 DEBUG : both7: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/03/11 07:38:01 DEBUG : both7: Unchanged skipping 2025/03/11 07:38:01 DEBUG : both8: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/03/11 07:38:01 DEBUG : both8: Unchanged skipping 2025/03/11 07:38:01 DEBUG : both9: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/03/11 07:38:01 DEBUG : both9: Unchanged skipping 2025/03/11 07:38:01 DEBUG : both1: Unchanged skipping 2025/03/11 07:38:01 DEBUG : both14: Unchanged skipping 2025/03/11 07:38:01 DEBUG : both17: Unchanged skipping 2025/03/11 07:38:01 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pefewaw2dupe': Waiting for transfers to finish 2025/03/11 07:38:01 DEBUG : Waiting for deletions to finish 2025/03/11 07:38:01 INFO : only11: Deleted 2025/03/11 07:38:01 INFO : only16: Deleted 2025/03/11 07:38:01 INFO : only8: Deleted 2025/03/11 07:38:01 INFO : only7: Deleted 2025/03/11 07:38:02 INFO : only15: Deleted 2025/03/11 07:38:02 INFO : only12: Deleted 2025/03/11 07:38:02 INFO : only17: Deleted 2025/03/11 07:38:02 INFO : only6: Deleted 2025/03/11 07:38:02 INFO : only10: Deleted 2025/03/11 07:38:02 INFO : only13: Deleted 2025/03/11 07:38:02 INFO : only19: Deleted 2025/03/11 07:38:02 INFO : only2: Deleted 2025/03/11 07:38:02 INFO : only4: Deleted 2025/03/11 07:38:03 INFO : only1: Deleted 2025/03/11 07:38:03 INFO : only3: Deleted 2025/03/11 07:38:03 INFO : only14: Deleted 2025/03/11 07:38:03 INFO : only9: Deleted 2025/03/11 07:38:03 INFO : only5: Deleted 2025/03/11 07:38:03 INFO : only0: Deleted 2025/03/11 07:38:03 INFO : only18: Deleted 2025/03/11 07:38:03 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pefewaw2dupe'", Local "Local file system at /tmp/rclone22493455", Modify Window "1ms" --- PASS: TestSyncConcurrentDelete (69.82s) === RUN TestSyncConcurrentTruncate run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pefewaw2dupe'", Local "Local file system at /tmp/rclone22493455", Modify Window "1ms" 2025/03/11 07:38:15 DEBUG : both0: md5 = be93bc9e9a74ba1224dfcd4c6e1eec9a OK 2025/03/11 07:38:17 DEBUG : only0: md5 = 3d6d4224d24af42d6aaae680221c5bb3 OK 2025/03/11 07:38:18 DEBUG : both1: md5 = 824dffa01966f29e0d4bf81fc1967ac4 OK 2025/03/11 07:38:20 DEBUG : only1: md5 = 0592770352b3c35015d93b9b73e6875b OK 2025/03/11 07:38:21 DEBUG : both2: md5 = e85246bb7c07b6b0575d86efb46e1796 OK 2025/03/11 07:38:22 DEBUG : only2: md5 = 03a9bdf402f99dbaaf5fb42345c6fffb OK 2025/03/11 07:38:24 DEBUG : both3: md5 = a8e7c00471884d5224a66c16bad2e52c OK 2025/03/11 07:38:25 DEBUG : only3: md5 = d7f3f9c68e2838858ba61b0d9df285bc OK 2025/03/11 07:38:26 DEBUG : both4: md5 = 7e45e4d4a7898cb6672da9f499d03c14 OK 2025/03/11 07:38:28 DEBUG : only4: md5 = 28fcf05e410880c45a0abd52536ca740 OK 2025/03/11 07:38:29 DEBUG : both5: md5 = 6b7501323e6d1173bd1608ca1acffa25 OK 2025/03/11 07:38:31 DEBUG : only5: md5 = b62aab4c013eccedf4d5e0165ee2c00e OK 2025/03/11 07:38:32 DEBUG : both6: md5 = 03682b5bca6523feaae1de9b0837bf9f OK 2025/03/11 07:38:33 DEBUG : only6: md5 = 93082643638da36894d90d3b6a421d0c OK 2025/03/11 07:38:35 DEBUG : both7: md5 = 635b3a2212ff44a7e61d37ed6f6ddf95 OK 2025/03/11 07:38:36 DEBUG : only7: md5 = cf785b88164c0b0ef0694672669ca0df OK 2025/03/11 07:38:38 DEBUG : both8: md5 = 3c08fae42ae3bda4039b0c5e1d01e521 OK 2025/03/11 07:38:39 DEBUG : only8: md5 = 78d2afe30ec1cb4e4b068db3b392d504 OK 2025/03/11 07:38:40 DEBUG : both9: md5 = 86bbcee6505095409b1edff08744c21e OK 2025/03/11 07:38:42 DEBUG : only9: md5 = e2cabff093224ccea62c5af92d54308a OK 2025/03/11 07:38:43 DEBUG : both10: md5 = 8cbce7f900c385bd3711c8a1ccf1ce63 OK 2025/03/11 07:38:44 DEBUG : only10: md5 = 2f3b32f8de14b9fa9658e296f7498f57 OK 2025/03/11 07:38:46 DEBUG : both11: md5 = e1c5038fe4dbaa1c1e791286b10606b2 OK 2025/03/11 07:38:47 DEBUG : only11: md5 = 0b30084ef93c38db359863e0fdf6e2e6 OK 2025/03/11 07:38:49 DEBUG : both12: md5 = d4b118d134cfbfb7c5ba71b5a4f7f6bb OK 2025/03/11 07:38:50 DEBUG : only12: md5 = 7c438af5684b6fd1ff9f5f20418c26ed OK 2025/03/11 07:38:51 DEBUG : both13: md5 = 19002dfd8f3982202a3447075f0ec343 OK 2025/03/11 07:38:53 DEBUG : only13: md5 = 1aca806b49138041e467691c2eac8325 OK 2025/03/11 07:38:54 DEBUG : both14: md5 = 129422cb4f3baea6e543284d79ccf028 OK 2025/03/11 07:38:55 DEBUG : only14: md5 = cacb235a1d264c149f76c53ccf374275 OK 2025/03/11 07:38:57 DEBUG : both15: md5 = db804bcb79c77fd087487981fcdc913e OK 2025/03/11 07:38:58 DEBUG : only15: md5 = 268def38e9a42b8cb95bc5d9698337b2 OK 2025/03/11 07:39:00 DEBUG : both16: md5 = af850bfb76d8a2b422ddde96f3101e3c OK 2025/03/11 07:39:01 DEBUG : only16: md5 = 15ce9f9775613e84cce1bef0d32af4a7 OK 2025/03/11 07:39:03 DEBUG : both17: md5 = 5414b09070eb16c3c51366258afb18b6 OK 2025/03/11 07:39:04 DEBUG : only17: md5 = fead7a3919ca65a489bcf3a80dc51c25 OK 2025/03/11 07:39:05 DEBUG : both18: md5 = 730b41c764666d8e37a581d288330647 OK 2025/03/11 07:39:07 DEBUG : only18: md5 = b5103a6bfb78d87adc5f50cf49f028aa OK 2025/03/11 07:39:08 DEBUG : both19: md5 = 05fff8a00b1fd2b2e62a5e8f10cf2d1e OK 2025/03/11 07:39:09 DEBUG : only19: md5 = 27d2da3fb00d0d1f3d887fd534846258 OK 2025/03/11 07:39:10 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pefewaw2dupe': Waiting for checks to finish 2025/03/11 07:39:10 DEBUG : both1: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/03/11 07:39:10 DEBUG : both10: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/03/11 07:39:10 DEBUG : both11: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/03/11 07:39:10 DEBUG : both0: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/03/11 07:39:10 DEBUG : both1: Unchanged skipping 2025/03/11 07:39:10 DEBUG : both12: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/03/11 07:39:10 DEBUG : both12: Unchanged skipping 2025/03/11 07:39:10 DEBUG : both13: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/03/11 07:39:10 DEBUG : both10: Unchanged skipping 2025/03/11 07:39:10 DEBUG : both14: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/03/11 07:39:10 DEBUG : both11: Unchanged skipping 2025/03/11 07:39:10 DEBUG : both15: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/03/11 07:39:10 DEBUG : both0: Unchanged skipping 2025/03/11 07:39:10 DEBUG : both16: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/03/11 07:39:10 DEBUG : both15: Unchanged skipping 2025/03/11 07:39:10 DEBUG : both17: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/03/11 07:39:10 DEBUG : both16: Unchanged skipping 2025/03/11 07:39:10 DEBUG : both18: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/03/11 07:39:10 DEBUG : both18: Unchanged skipping 2025/03/11 07:39:10 DEBUG : both19: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/03/11 07:39:10 DEBUG : both19: Unchanged skipping 2025/03/11 07:39:10 DEBUG : both2: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/03/11 07:39:10 DEBUG : both2: Unchanged skipping 2025/03/11 07:39:10 DEBUG : both3: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/03/11 07:39:10 DEBUG : both3: Unchanged skipping 2025/03/11 07:39:10 DEBUG : both4: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/03/11 07:39:10 DEBUG : both14: Unchanged skipping 2025/03/11 07:39:10 DEBUG : both5: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/03/11 07:39:10 DEBUG : both5: Unchanged skipping 2025/03/11 07:39:10 DEBUG : both6: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/03/11 07:39:10 DEBUG : both13: Unchanged skipping 2025/03/11 07:39:10 DEBUG : both7: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/03/11 07:39:10 DEBUG : both7: Unchanged skipping 2025/03/11 07:39:10 DEBUG : both8: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/03/11 07:39:10 DEBUG : both8: Unchanged skipping 2025/03/11 07:39:10 DEBUG : both9: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/03/11 07:39:10 DEBUG : both9: Unchanged skipping 2025/03/11 07:39:10 DEBUG : only0: Sizes differ (src 0 vs dst 6) 2025/03/11 07:39:10 DEBUG : only1: Sizes differ (src 0 vs dst 6) 2025/03/11 07:39:10 DEBUG : only10: Sizes differ (src 0 vs dst 6) 2025/03/11 07:39:10 DEBUG : only11: Sizes differ (src 0 vs dst 6) 2025/03/11 07:39:10 DEBUG : only12: Sizes differ (src 0 vs dst 6) 2025/03/11 07:39:10 DEBUG : only13: Sizes differ (src 0 vs dst 6) 2025/03/11 07:39:10 DEBUG : only14: Sizes differ (src 0 vs dst 6) 2025/03/11 07:39:10 DEBUG : only15: Sizes differ (src 0 vs dst 6) 2025/03/11 07:39:10 DEBUG : only16: Sizes differ (src 0 vs dst 6) 2025/03/11 07:39:10 DEBUG : only17: Sizes differ (src 0 vs dst 6) 2025/03/11 07:39:10 DEBUG : only18: Sizes differ (src 0 vs dst 6) 2025/03/11 07:39:10 DEBUG : only19: Sizes differ (src 0 vs dst 6) 2025/03/11 07:39:10 DEBUG : only2: Sizes differ (src 0 vs dst 6) 2025/03/11 07:39:10 DEBUG : only3: Sizes differ (src 0 vs dst 6) 2025/03/11 07:39:10 DEBUG : only4: Sizes differ (src 0 vs dst 6) 2025/03/11 07:39:10 DEBUG : only5: Sizes differ (src 0 vs dst 6) 2025/03/11 07:39:10 DEBUG : only6: Sizes differ (src 0 vs dst 6) 2025/03/11 07:39:10 DEBUG : only7: Sizes differ (src 0 vs dst 6) 2025/03/11 07:39:10 DEBUG : only8: Sizes differ (src 0 vs dst 6) 2025/03/11 07:39:10 DEBUG : only9: Sizes differ (src 0 vs dst 6) 2025/03/11 07:39:10 DEBUG : both17: Unchanged skipping 2025/03/11 07:39:10 DEBUG : both4: Unchanged skipping 2025/03/11 07:39:10 DEBUG : both6: Unchanged skipping 2025/03/11 07:39:10 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pefewaw2dupe': Waiting for transfers to finish 2025/03/11 07:39:11 DEBUG : only11: md5 = 8c801b296fa2d33f33a58c94f7a3f3c2 OK 2025/03/11 07:39:11 INFO : only11: Copied (replaced existing) 2025/03/11 07:39:11 DEBUG : only0: md5 = 4f4d6e41598c6e7919f8fef094a1a489 OK 2025/03/11 07:39:11 INFO : only0: Copied (replaced existing) 2025/03/11 07:39:11 DEBUG : only1: md5 = b6129c25c493ce2503c424ecd7d1d6bf OK 2025/03/11 07:39:11 INFO : only1: Copied (replaced existing) 2025/03/11 07:39:11 DEBUG : only10: md5 = 4ff67b34b6c08cce00d4d2e1387b3120 OK 2025/03/11 07:39:11 INFO : only10: Copied (replaced existing) 2025/03/11 07:39:12 DEBUG : only12: md5 = 0fc6ad8940bb24dcc338ea0aede85739 OK 2025/03/11 07:39:12 INFO : only12: Copied (replaced existing) 2025/03/11 07:39:12 DEBUG : only15: md5 = 26c7694b567a05cac28b29eca6d29b30 OK 2025/03/11 07:39:12 INFO : only15: Copied (replaced existing) 2025/03/11 07:39:12 DEBUG : only13: md5 = 96878f3129756b0ef8424c1252a7f697 OK 2025/03/11 07:39:12 INFO : only13: Copied (replaced existing) 2025/03/11 07:39:13 DEBUG : only14: md5 = 7b5b7b9cd7c146a5b3171a6b8287bd0d OK 2025/03/11 07:39:13 INFO : only14: Copied (replaced existing) 2025/03/11 07:39:14 DEBUG : only18: md5 = c021b900f1ef839e2287469dc258e09f OK 2025/03/11 07:39:14 INFO : only18: Copied (replaced existing) 2025/03/11 07:39:14 DEBUG : only16: md5 = 7f1a8ac296b6bd518c932c45aea554d4 OK 2025/03/11 07:39:14 INFO : only16: Copied (replaced existing) 2025/03/11 07:39:14 DEBUG : only17: md5 = aecc14dfc25ace49fdd57f499a8de8a1 OK 2025/03/11 07:39:14 INFO : only17: Copied (replaced existing) 2025/03/11 07:39:14 DEBUG : only19: md5 = 165641eedf183ab5039624f75cb08fd4 OK 2025/03/11 07:39:14 INFO : only19: Copied (replaced existing) 2025/03/11 07:39:15 DEBUG : only2: md5 = fb59e935b54da12f2d315f3387fc655f OK 2025/03/11 07:39:15 INFO : only2: Copied (replaced existing) 2025/03/11 07:39:15 DEBUG : only4: md5 = 59629a560cd99120de97d766f7c402d7 OK 2025/03/11 07:39:15 INFO : only4: Copied (replaced existing) 2025/03/11 07:39:15 DEBUG : only5: md5 = aa945269edc192dee86a2c53cca85ad9 OK 2025/03/11 07:39:15 INFO : only5: Copied (replaced existing) 2025/03/11 07:39:15 DEBUG : only3: md5 = f0ac1e61fca81f09dc46ce2aebc003dd OK 2025/03/11 07:39:15 INFO : only3: Copied (replaced existing) 2025/03/11 07:39:16 DEBUG : only7: md5 = b18acf38b43074078551d578edabc66e OK 2025/03/11 07:39:16 INFO : only7: Copied (replaced existing) 2025/03/11 07:39:16 DEBUG : only8: md5 = c3d6026315f5f2a7831b1ca9301cd642 OK 2025/03/11 07:39:16 INFO : only8: Copied (replaced existing) 2025/03/11 07:39:16 DEBUG : only6: md5 = 0a07c175de06fa1fcee896516d922929 OK 2025/03/11 07:39:16 INFO : only6: Copied (replaced existing) 2025/03/11 07:39:16 DEBUG : only9: md5 = 8e1201232d6c5a5440961bbaa54a9b80 OK 2025/03/11 07:39:16 INFO : only9: Copied (replaced existing) 2025/03/11 07:39:16 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pefewaw2dupe'", Local "Local file system at /tmp/rclone22493455", Modify Window "1ms" --- PASS: TestSyncConcurrentTruncate (82.79s) === RUN TestSyncReplaceDirModTime run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pefewaw2dupe'", Local "Local file system at /tmp/rclone22493455", Modify Window "1ms" 2025/03/11 07:39:37 DEBUG : empty_dir: Making directory with metadata 2025/03/11 07:39:37 INFO : empty_dir: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2025/03/11 07:39:37 DEBUG : empty_on_remote: Making directory with metadata 2025/03/11 07:39:37 INFO : empty_on_remote: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2025/03/11 07:39:37 DEBUG : empty_on_remote: Making directory with metadata 2025/03/11 07:39:37 INFO : empty_on_remote: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pefewaw2dupe'", Local "Local file system at /tmp/rclone22493455", Modify Window "1ms" 2025/03/11 07:39:43 INFO : test_dir1: Set directory modification time (using DirSetModTime) 2025/03/11 07:39:43 INFO : test_dir2: Set directory modification time (using DirSetModTime) 2025/03/11 07:39:43 INFO : test_dir2/sub_dir: Set directory modification time (using DirSetModTime) 2025/03/11 07:39:43 INFO : empty_on_remote: Set directory modification time (using DirSetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pefewaw2dupe'", Local "Local file system at /tmp/rclone22493455", Modify Window "1ms" 2025/03/11 07:39:50 DEBUG : heqj02jg0dcqlem7gl0500bvp0/24g2k8bseitblkmqnie1ibl2s8: Rmdir: contains trashed file: "633fmaa0qic3kv3cladnu11pto" 2025/03/11 07:39:51 DEBUG : heqj02jg0dcqlem7gl0500bvp0: Rmdir: contains trashed file: "24g2k8bseitblkmqnie1ibl2s8" 2025/03/11 07:39:51 DEBUG : gq68srrpl0nnf394bgf7dbu9kc: Rmdir: contains trashed file: "d26uovf0miqhd1mu3c9jbseq00" --- PASS: TestSyncReplaceDirModTime (17.00s) === RUN TestSyncReplaceDirModTimeWithEmptyDirs run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pefewaw2dupe'", Local "Local file system at /tmp/rclone22493455", Modify Window "1ms" 2025/03/11 07:39:54 DEBUG : empty_dir: Making directory with metadata 2025/03/11 07:39:54 INFO : empty_dir: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2025/03/11 07:39:54 DEBUG : empty_on_remote: Making directory with metadata 2025/03/11 07:39:54 INFO : empty_on_remote: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2025/03/11 07:39:54 DEBUG : empty_on_remote: Making directory with metadata 2025/03/11 07:39:55 INFO : empty_on_remote: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pefewaw2dupe'", Local "Local file system at /tmp/rclone22493455", Modify Window "1ms" 2025/03/11 07:40:00 INFO : test_dir1: Set directory modification time (using DirSetModTime) 2025/03/11 07:40:00 INFO : test_dir2: Set directory modification time (using DirSetModTime) 2025/03/11 07:40:00 INFO : test_dir2/sub_dir: Set directory modification time (using DirSetModTime) 2025/03/11 07:40:00 INFO : empty_on_remote: Set directory modification time (using DirSetModTime) 2025/03/11 07:40:00 INFO : empty_dir: Set directory modification time (using DirSetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pefewaw2dupe'", Local "Local file system at /tmp/rclone22493455", Modify Window "1ms" 2025/03/11 07:40:08 DEBUG : heqj02jg0dcqlem7gl0500bvp0/24g2k8bseitblkmqnie1ibl2s8: Rmdir: contains trashed file: "633fmaa0qic3kv3cladnu11pto" 2025/03/11 07:40:08 DEBUG : heqj02jg0dcqlem7gl0500bvp0: Rmdir: contains trashed file: "24g2k8bseitblkmqnie1ibl2s8" 2025/03/11 07:40:09 DEBUG : gq68srrpl0nnf394bgf7dbu9kc: Rmdir: contains trashed file: "d26uovf0miqhd1mu3c9jbseq00" --- PASS: TestSyncReplaceDirModTimeWithEmptyDirs (18.47s) === RUN TestNothingToTransferWithEmptyDirs run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pefewaw2dupe'", Local "Local file system at /tmp/rclone22493455", Modify Window "1ms" 2025/03/11 07:40:12 INFO : sub dir: Set directory modification time (using DirSetModTime) 2025/03/11 07:40:12 DEBUG : sub dir: Making directory with metadata 2025/03/11 07:40:13 INFO : sub dir: Made directory with metadata (mtime=2011-12-30T12:59:59Z) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pefewaw2dupe'", Local "Local file system at /tmp/rclone22493455", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pefewaw2dupe'", Local "Local file system at /tmp/rclone22493455", Modify Window "1ms" 2025/03/11 07:40:31 INFO : sub dir2: Set directory modification time (using DirSetModTime) 2025/03/11 07:40:31 INFO : sub dir2: Set directory modification time (using DirSetModTime) 2025/03/11 07:40:31 INFO : sub dirEmpty/sub dirEmpty2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2025/03/11 07:40:31 INFO : sub dirEmpty: Set directory modification time (using DirSetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pefewaw2dupe'", Local "Local file system at /tmp/rclone22493455", Modify Window "1ms" 2025/03/11 07:40:46 DEBUG : gcsdkq814sbtppue42dpsbg8ug: Rmdir: contains trashed file: "sjuo65gk5q3r1199jselk9k9o0" 2025/03/11 07:40:47 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/37qp6d1gohacv723ij3brofbu8/i24n0ln37pa2hv8pctddeuh73o: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" 2025/03/11 07:40:48 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/37qp6d1gohacv723ij3brofbu8: Rmdir: contains trashed file: "i24n0ln37pa2hv8pctddeuh73o" 2025/03/11 07:40:48 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "37qp6d1gohacv723ij3brofbu8" 2025/03/11 07:40:49 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak" 2025/03/11 07:40:50 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak" 2025/03/11 07:40:51 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak" 2025/03/11 07:40:51 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak" 2025/03/11 07:40:52 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/4r13oncfa2rsrr82oqhsqv24ns: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" 2025/03/11 07:40:53 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc: Rmdir: contains trashed file: "4r13oncfa2rsrr82oqhsqv24ns" 2025/03/11 07:40:53 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak" 2025/03/11 07:40:53 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestNothingToTransferWithEmptyDirs (43.36s) === RUN TestNothingToTransferWithoutEmptyDirs run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pefewaw2dupe'", Local "Local file system at /tmp/rclone22493455", Modify Window "1ms" 2025/03/11 07:40:56 INFO : sub dir: Set directory modification time (using DirSetModTime) 2025/03/11 07:40:56 DEBUG : sub dir: Making directory with metadata 2025/03/11 07:40:56 INFO : sub dir: Made directory with metadata (mtime=2011-12-30T12:59:59Z) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pefewaw2dupe'", Local "Local file system at /tmp/rclone22493455", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pefewaw2dupe'", Local "Local file system at /tmp/rclone22493455", Modify Window "1ms" 2025/03/11 07:41:18 INFO : sub dir2: Set directory modification time (using DirSetModTime) 2025/03/11 07:41:19 INFO : sub dir2: Set directory modification time (using DirSetModTime) 2025/03/11 07:41:19 INFO : sub dirEmpty/sub dirEmpty2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2025/03/11 07:41:19 INFO : sub dirEmpty: Set directory modification time (using DirSetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-pefewaw2dupe'", Local "Local file system at /tmp/rclone22493455", Modify Window "1ms" 2025/03/11 07:41:32 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/37qp6d1gohacv723ij3brofbu8/i24n0ln37pa2hv8pctddeuh73o: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" 2025/03/11 07:41:33 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/37qp6d1gohacv723ij3brofbu8: Rmdir: contains trashed file: "i24n0ln37pa2hv8pctddeuh73o" 2025/03/11 07:41:34 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "37qp6d1gohacv723ij3brofbu8" 2025/03/11 07:41:34 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak" 2025/03/11 07:41:35 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak" 2025/03/11 07:41:36 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak" 2025/03/11 07:41:36 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak" 2025/03/11 07:41:37 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/4r13oncfa2rsrr82oqhsqv24ns: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" 2025/03/11 07:41:38 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc: Rmdir: contains trashed file: "4r13oncfa2rsrr82oqhsqv24ns" 2025/03/11 07:41:38 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak" 2025/03/11 07:41:39 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestNothingToTransferWithoutEmptyDirs (45.30s) PASS 2025/03/11 07:41:41 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pefewaw2dupe': Purge remote "./sync.test -test.v -test.timeout 1h0m0s -remote TestCryptDrive: -verbose -fast-list" - Finished OK in 16m58.355728693s (try 1/5)