"./sync.test -test.v -test.timeout 1h0m0s -remote TestCryptDrive: -verbose -fast-list" - Starting (try 1/5) 2025/04/15 05:19:15 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-dovuxej0zopu" 2025/04/15 05:19:15 DEBUG : Using config file from "/home/rclone/.rclone.conf" 2025/04/15 05:19:15 DEBUG : Creating backend with remote "TestDrive:crypt/smlh8e653n38ba8jg0ed6f8tncp8o8vm9ic9r24gp4sdufv0g7r0" 2025/04/15 05:19:16 DEBUG : Creating backend with remote "/tmp/rclone1859944754" === RUN TestPipe --- PASS: TestPipe (0.00s) === RUN TestPipeConcurrent --- PASS: TestPipeConcurrent (0.03s) === RUN TestPipeOrderBy === RUN TestPipeOrderBy/#00 === RUN TestPipeOrderBy/size === RUN TestPipeOrderBy/name === RUN TestPipeOrderBy/modtime === RUN TestPipeOrderBy/size,ascending === RUN TestPipeOrderBy/name,asc === RUN TestPipeOrderBy/modtime,ascending === RUN TestPipeOrderBy/size,descending === RUN TestPipeOrderBy/name,desc === RUN TestPipeOrderBy/modtime,descending === RUN TestPipeOrderBy/size,mixed,50 === RUN TestPipeOrderBy/size,mixed,51 --- PASS: TestPipeOrderBy (0.00s) --- PASS: TestPipeOrderBy/#00 (0.00s) --- PASS: TestPipeOrderBy/size (0.00s) --- PASS: TestPipeOrderBy/name (0.00s) --- PASS: TestPipeOrderBy/modtime (0.00s) --- PASS: TestPipeOrderBy/size,ascending (0.00s) --- PASS: TestPipeOrderBy/name,asc (0.00s) --- PASS: TestPipeOrderBy/modtime,ascending (0.00s) --- PASS: TestPipeOrderBy/size,descending (0.00s) --- PASS: TestPipeOrderBy/name,desc (0.00s) --- PASS: TestPipeOrderBy/modtime,descending (0.00s) --- PASS: TestPipeOrderBy/size,mixed,50 (0.00s) --- PASS: TestPipeOrderBy/size,mixed,51 (0.00s) === RUN TestNewLess === RUN TestNewLess/blankOK === RUN TestNewLess/tooManyParts === RUN TestNewLess/tooManyParts2 === RUN TestNewLess/badMixed === RUN TestNewLess/unknownComparison === RUN TestNewLess/unknownSortDirection === RUN TestNewLess/size === RUN TestNewLess/name === RUN TestNewLess/modtime === RUN TestNewLess/size,ascending === RUN TestNewLess/name,asc === RUN TestNewLess/modtime,ascending === RUN TestNewLess/size,descending === RUN TestNewLess/name,desc === RUN TestNewLess/modtime,descending === RUN TestNewLess/modtime,mixed === RUN TestNewLess/modtime,mixed,30 --- PASS: TestNewLess (0.00s) --- PASS: TestNewLess/blankOK (0.00s) --- PASS: TestNewLess/tooManyParts (0.00s) --- PASS: TestNewLess/tooManyParts2 (0.00s) --- PASS: TestNewLess/badMixed (0.00s) --- PASS: TestNewLess/unknownComparison (0.00s) --- PASS: TestNewLess/unknownSortDirection (0.00s) --- PASS: TestNewLess/size (0.00s) --- PASS: TestNewLess/name (0.00s) --- PASS: TestNewLess/modtime (0.00s) --- PASS: TestNewLess/size,ascending (0.00s) --- PASS: TestNewLess/name,asc (0.00s) --- PASS: TestNewLess/modtime,ascending (0.00s) --- PASS: TestNewLess/size,descending (0.00s) --- PASS: TestNewLess/name,desc (0.00s) --- PASS: TestNewLess/modtime,descending (0.00s) --- PASS: TestNewLess/modtime,mixed (0.00s) --- PASS: TestNewLess/modtime,mixed,30 (0.00s) === RUN TestRcCopy rc_test.go:16: Skipping test on non local remote --- SKIP: TestRcCopy (0.00s) === RUN TestRcMove rc_test.go:16: Skipping test on non local remote --- SKIP: TestRcMove (0.00s) === RUN TestRcSync rc_test.go:16: Skipping test on non local remote --- SKIP: TestRcSync (0.00s) === RUN TestCopyWithDryRun run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dovuxej0zopu'", Local "Local file system at /tmp/rclone1859944754", Modify Window "1ms" 2025/04/15 05:19:17 DEBUG : Added delayed dir = "sub dir", newDst= 2025/04/15 05:19:17 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2025/04/15 05:19:17 NOTICE: sub dir/hello world: Skipped copy as --dry-run is set (size 11) 2025/04/15 05:19:17 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dovuxej0zopu': Waiting for checks to finish 2025/04/15 05:19:17 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dovuxej0zopu': Waiting for transfers to finish 2025/04/15 05:19:17 NOTICE: sub dir: Skipped set directory modification time as --dry-run is set run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dovuxej0zopu'", Local "Local file system at /tmp/rclone1859944754", Modify Window "1ms" --- PASS: TestCopyWithDryRun (2.32s) === RUN TestCopy run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dovuxej0zopu'", Local "Local file system at /tmp/rclone1859944754", Modify Window "1ms" 2025/04/15 05:19:18 INFO : sub dir: Set directory modification time (using DirSetModTime) 2025/04/15 05:19:19 DEBUG : Added delayed dir = "sub dir", newDst= 2025/04/15 05:19:19 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2025/04/15 05:19:19 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dovuxej0zopu': Waiting for checks to finish 2025/04/15 05:19:19 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dovuxej0zopu': Waiting for transfers to finish 2025/04/15 05:19:21 DEBUG : sub dir/hello world: md5 = 27f124d0c0cf6b85db72d6561913c2e0 OK 2025/04/15 05:19:21 INFO : sub dir/hello world: Copied (new) 2025/04/15 05:19:22 INFO : sub dir: Set directory modification time (using DirSetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dovuxej0zopu'", Local "Local file system at /tmp/rclone1859944754", Modify Window "1ms" 2025/04/15 05:19:24 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestCopy (6.67s) === RUN TestCopyMetadata run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dovuxej0zopu'", Local "Local file system at /tmp/rclone1859944754", Modify Window "1ms" 2025/04/15 05:19:25 DEBUG : metadata sub dir: Making directory with metadata 2025/04/15 05:19:25 INFO : metadata sub dir: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2025/04/15 05:19:25 DEBUG : empty metadata sub dir: Making directory with metadata 2025/04/15 05:19:25 INFO : empty metadata sub dir: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2025/04/15 05:19:25 DEBUG : Local file system at /tmp/rclone1859944754: File to upload is small (21 bytes), uploading instead of streaming 2025/04/15 05:19:25 DEBUG : metadata sub dir/hello metadata world: md5 = baa7a013449dbba2b1ed02b5cfb4e1a2 OK 2025/04/15 05:19:25 DEBUG : metadata sub dir/hello metadata world: Size and md5 of src and dst objects identical 2025/04/15 05:19:25 INFO : metadata sub dir: Set directory modification time (using DirSetModTime) 2025/04/15 05:19:26 DEBUG : Google drive root 'crypt/smlh8e653n38ba8jg0ed6f8tncp8o8vm9ic9r24gp4sdufv0g7r0': Skipping btime metadata as can't update it on an existing file: 2025-04-15T05:19:25.560695983Z 2025/04/15 05:19:26 INFO : empty metadata sub dir: Updated directory metadata 2025/04/15 05:19:26 DEBUG : Google drive root 'crypt/smlh8e653n38ba8jg0ed6f8tncp8o8vm9ic9r24gp4sdufv0g7r0': Skipping btime metadata as can't update it on an existing file: 2025-04-15T05:19:25.560695983Z 2025/04/15 05:19:27 INFO : metadata sub dir: Updated directory metadata 2025/04/15 05:19:27 DEBUG : metadata sub dir/hello metadata world: Need to transfer - File not found at Destination 2025/04/15 05:19:27 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dovuxej0zopu': Waiting for checks to finish 2025/04/15 05:19:27 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dovuxej0zopu': Waiting for transfers to finish 2025/04/15 05:19:28 DEBUG : metadata sub dir/hello metadata world: md5 = c062cad1263a47e71d520a9e59be91c1 OK 2025/04/15 05:19:28 INFO : metadata sub dir/hello metadata world: Copied (new) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dovuxej0zopu'", Local "Local file system at /tmp/rclone1859944754", Modify Window "1ms" 2025/04/15 05:19:31 DEBUG : fg45q1rm3kh00nmmkk4m6ihmrcnel1p7551kqhjr9bk2gtd2gbf0: Rmdir: contains trashed file: "dmuvulfij81f693ur0f1vvbvq9v6iscp56daas3m51n9li5e3470" --- PASS: TestCopyMetadata (7.94s) === RUN TestCopyMetadataNoEmptyDirs run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dovuxej0zopu'", Local "Local file system at /tmp/rclone1859944754", Modify Window "1ms" 2025/04/15 05:19:33 DEBUG : metadata sub dir: Making directory with metadata 2025/04/15 05:19:33 INFO : metadata sub dir: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2025/04/15 05:19:33 DEBUG : empty metadata sub dir: Making directory with metadata 2025/04/15 05:19:33 INFO : empty metadata sub dir: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2025/04/15 05:19:33 DEBUG : Local file system at /tmp/rclone1859944754: File to upload is small (21 bytes), uploading instead of streaming 2025/04/15 05:19:33 DEBUG : metadata sub dir/hello metadata world: md5 = baa7a013449dbba2b1ed02b5cfb4e1a2 OK 2025/04/15 05:19:33 DEBUG : metadata sub dir/hello metadata world: Size and md5 of src and dst objects identical 2025/04/15 05:19:33 INFO : metadata sub dir: Set directory modification time (using DirSetModTime) 2025/04/15 05:19:33 DEBUG : Added delayed dir = "empty metadata sub dir", newDst= 2025/04/15 05:19:33 DEBUG : Added delayed dir = "metadata sub dir", newDst= 2025/04/15 05:19:33 DEBUG : metadata sub dir/hello metadata world: Need to transfer - File not found at Destination 2025/04/15 05:19:33 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dovuxej0zopu': Waiting for checks to finish 2025/04/15 05:19:33 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dovuxej0zopu': Waiting for transfers to finish 2025/04/15 05:19:35 DEBUG : metadata sub dir/hello metadata world: md5 = 40e46e254585572300c09a68272c98c3 OK 2025/04/15 05:19:35 INFO : metadata sub dir/hello metadata world: Copied (new) 2025/04/15 05:19:35 DEBUG : Google drive root 'crypt/smlh8e653n38ba8jg0ed6f8tncp8o8vm9ic9r24gp4sdufv0g7r0': Skipping btime metadata as can't update it on an existing file: 2025-04-15T05:19:33.496707217Z 2025/04/15 05:19:36 INFO : metadata sub dir: Updated directory metadata run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dovuxej0zopu'", Local "Local file system at /tmp/rclone1859944754", Modify Window "1ms" 2025/04/15 05:19:39 DEBUG : fg45q1rm3kh00nmmkk4m6ihmrcnel1p7551kqhjr9bk2gtd2gbf0: Rmdir: contains trashed file: "dmuvulfij81f693ur0f1vvbvq9v6iscp56daas3m51n9li5e3470" --- PASS: TestCopyMetadataNoEmptyDirs (7.03s) === RUN TestCopyMissingDirectory run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dovuxej0zopu'", Local "Local file system at /tmp/rclone1859944754", Modify Window "1ms" 2025/04/15 05:19:40 DEBUG : Creating backend with remote "/non-existing" 2025/04/15 05:19:40 ERROR : Local file system at /non-existing: error reading source root directory: directory not found 2025/04/15 05:19:40 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dovuxej0zopu': Waiting for checks to finish 2025/04/15 05:19:40 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dovuxej0zopu': Waiting for transfers to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dovuxej0zopu'", Local "Local file system at /tmp/rclone1859944754", Modify Window "1ms" --- PASS: TestCopyMissingDirectory (1.11s) === RUN TestCopyNoTraverse run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dovuxej0zopu'", Local "Local file system at /tmp/rclone1859944754", Modify Window "1ms" 2025/04/15 05:19:41 DEBUG : Added delayed dir = "sub dir", newDst= 2025/04/15 05:19:41 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2025/04/15 05:19:41 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dovuxej0zopu': Waiting for checks to finish 2025/04/15 05:19:41 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dovuxej0zopu': Waiting for transfers to finish 2025/04/15 05:19:43 DEBUG : sub dir/hello world: md5 = 5030c7ceae438b7d7f91ea5302d1dc5b OK 2025/04/15 05:19:43 INFO : sub dir/hello world: Copied (new) 2025/04/15 05:19:44 INFO : sub dir: Set directory modification time (using DirSetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dovuxej0zopu'", Local "Local file system at /tmp/rclone1859944754", Modify Window "1ms" 2025/04/15 05:19:46 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestCopyNoTraverse (5.80s) === RUN TestCopyCheckFirst run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dovuxej0zopu'", Local "Local file system at /tmp/rclone1859944754", Modify Window "1ms" 2025/04/15 05:19:47 INFO : Encrypted drive 'TestCryptDrive:rclone-test-dovuxej0zopu': Running all checks before starting transfers 2025/04/15 05:19:47 DEBUG : Added delayed dir = "sub dir", newDst= 2025/04/15 05:19:47 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2025/04/15 05:19:47 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dovuxej0zopu': Waiting for checks to finish 2025/04/15 05:19:47 INFO : Encrypted drive 'TestCryptDrive:rclone-test-dovuxej0zopu': Checks finished, now starting transfers 2025/04/15 05:19:47 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dovuxej0zopu': Waiting for transfers to finish 2025/04/15 05:19:50 DEBUG : sub dir/hello world: md5 = 0948a0ab3017f5b16b809b2a1682e7d3 OK 2025/04/15 05:19:50 INFO : sub dir/hello world: Copied (new) 2025/04/15 05:19:50 INFO : sub dir: Set directory modification time (using DirSetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dovuxej0zopu'", Local "Local file system at /tmp/rclone1859944754", Modify Window "1ms" 2025/04/15 05:19:52 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestCopyCheckFirst (6.24s) === RUN TestSyncNoTraverse run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dovuxej0zopu'", Local "Local file system at /tmp/rclone1859944754", Modify Window "1ms" 2025/04/15 05:19:53 ERROR : Ignoring --no-traverse with sync 2025/04/15 05:19:53 DEBUG : Added delayed dir = "sub dir", newDst= 2025/04/15 05:19:53 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2025/04/15 05:19:53 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dovuxej0zopu': Waiting for checks to finish 2025/04/15 05:19:53 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dovuxej0zopu': Waiting for transfers to finish 2025/04/15 05:19:56 DEBUG : sub dir/hello world: md5 = 9a339b085b8fed2a8ec1c66f228e5d41 OK 2025/04/15 05:19:56 INFO : sub dir/hello world: Copied (new) 2025/04/15 05:19:56 DEBUG : Waiting for deletions to finish 2025/04/15 05:19:56 INFO : sub dir: Set directory modification time (using DirSetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dovuxej0zopu'", Local "Local file system at /tmp/rclone1859944754", Modify Window "1ms" 2025/04/15 05:19:58 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestSyncNoTraverse (5.99s) === RUN TestCopyWithDepth run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dovuxej0zopu'", Local "Local file system at /tmp/rclone1859944754", Modify Window "1ms" 2025/04/15 05:19:59 DEBUG : hello world2: Need to transfer - File not found at Destination 2025/04/15 05:19:59 DEBUG : Added delayed dir = "sub dir", newDst= 2025/04/15 05:19:59 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dovuxej0zopu': Waiting for checks to finish 2025/04/15 05:19:59 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dovuxej0zopu': Waiting for transfers to finish 2025/04/15 05:20:01 DEBUG : hello world2: md5 = 1aa3b2b275a643e94553dffb5673332f OK 2025/04/15 05:20:01 INFO : hello world2: Copied (new) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dovuxej0zopu'", Local "Local file system at /tmp/rclone1859944754", Modify Window "1ms" --- PASS: TestCopyWithDepth (3.24s) === RUN TestCopyWithFilesFrom run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dovuxej0zopu'", Local "Local file system at /tmp/rclone1859944754", Modify Window "1ms" 2025/04/15 05:20:03 DEBUG : potato2: Need to transfer - File not found at Destination 2025/04/15 05:20:03 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dovuxej0zopu': Waiting for checks to finish 2025/04/15 05:20:03 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dovuxej0zopu': Waiting for transfers to finish 2025/04/15 05:20:04 DEBUG : potato2: md5 = 0f60f9fa7a7f31887edbca5be3d5812c OK 2025/04/15 05:20:04 INFO : potato2: Copied (new) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dovuxej0zopu'", Local "Local file system at /tmp/rclone1859944754", Modify Window "1ms" --- PASS: TestCopyWithFilesFrom (3.39s) === RUN TestCopyWithFilesFromAndNoTraverse run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dovuxej0zopu'", Local "Local file system at /tmp/rclone1859944754", Modify Window "1ms" 2025/04/15 05:20:06 DEBUG : potato2: Need to transfer - File not found at Destination 2025/04/15 05:20:06 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dovuxej0zopu': Waiting for checks to finish 2025/04/15 05:20:06 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dovuxej0zopu': Waiting for transfers to finish 2025/04/15 05:20:08 DEBUG : potato2: md5 = 1b7e9077abaac0f8c434fb58b922b8f0 OK 2025/04/15 05:20:08 INFO : potato2: Copied (new) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dovuxej0zopu'", Local "Local file system at /tmp/rclone1859944754", Modify Window "1ms" --- PASS: TestCopyWithFilesFromAndNoTraverse (3.35s) === RUN TestCopyEmptyDirectories run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dovuxej0zopu'", Local "Local file system at /tmp/rclone1859944754", Modify Window "1ms" 2025/04/15 05:20:09 DEBUG : sub dir2/sub sub dir2: Making directory with metadata 2025/04/15 05:20:09 INFO : sub dir2/sub sub dir2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2025/04/15 05:20:09 INFO : sub dir2: Set directory modification time (using DirSetModTime) 2025/04/15 05:20:09 INFO : sub dir: Set directory modification time (using DirSetModTime) 2025/04/15 05:20:09 DEBUG : sub dir: Making directory with metadata 2025/04/15 05:20:10 INFO : sub dir: Made directory with metadata (mtime=2001-02-03T04:05:06.499999999Z) 2025/04/15 05:20:10 DEBUG : sub dir2: Making directory with metadata 2025/04/15 05:20:11 INFO : sub dir2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2025/04/15 05:20:11 DEBUG : sub dir2/sub sub dir2: Making directory with metadata 2025/04/15 05:20:11 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2025/04/15 05:20:12 INFO : sub dir2/sub sub dir2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2025/04/15 05:20:12 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dovuxej0zopu': Waiting for checks to finish 2025/04/15 05:20:12 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dovuxej0zopu': Waiting for transfers to finish 2025/04/15 05:20:13 DEBUG : sub dir/hello world: md5 = de6c1ef397b1c4f7ede22ab49c01c408 OK 2025/04/15 05:20:13 INFO : sub dir/hello world: Copied (new) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dovuxej0zopu'", Local "Local file system at /tmp/rclone1859944754", Modify Window "1ms" 2025/04/15 05:20:16 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc: Rmdir: contains trashed file: "cv6a9uf28ngrajena8kt5ijjn0" 2025/04/15 05:20:17 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestCopyEmptyDirectories (8.90s) === RUN TestCopyNoEmptyDirectories run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dovuxej0zopu'", Local "Local file system at /tmp/rclone1859944754", Modify Window "1ms" 2025/04/15 05:20:18 INFO : sub dir2: Making directory 2025/04/15 05:20:18 DEBUG : sub dir2/sub sub dir2: Making directory with metadata 2025/04/15 05:20:18 INFO : sub dir2/sub sub dir2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2025/04/15 05:20:18 DEBUG : Added delayed dir = "sub dir", newDst= 2025/04/15 05:20:18 DEBUG : Added delayed dir = "sub dir2", newDst= 2025/04/15 05:20:18 DEBUG : Added delayed dir = "sub dir2/sub sub dir2", newDst= 2025/04/15 05:20:18 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2025/04/15 05:20:18 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dovuxej0zopu': Waiting for checks to finish 2025/04/15 05:20:18 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dovuxej0zopu': Waiting for transfers to finish 2025/04/15 05:20:20 DEBUG : sub dir/hello world: md5 = 6257095bfd4ee0077c91a64ee4337f89 OK 2025/04/15 05:20:20 INFO : sub dir/hello world: Copied (new) 2025/04/15 05:20:21 INFO : sub dir: Set directory modification time (using DirSetModTime) 2025/04/15 05:20:23 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestCopyNoEmptyDirectories (5.35s) === RUN TestMoveEmptyDirectories run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dovuxej0zopu'", Local "Local file system at /tmp/rclone1859944754", Modify Window "1ms" 2025/04/15 05:20:23 DEBUG : sub dir2: Making directory with metadata 2025/04/15 05:20:23 INFO : sub dir2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2025/04/15 05:20:24 DEBUG : sub dir: Making directory with metadata 2025/04/15 05:20:24 INFO : sub dir: Made directory with metadata (mtime=2025-04-15T05:20:23.912778769Z) 2025/04/15 05:20:24 DEBUG : sub dir2: Making directory with metadata 2025/04/15 05:20:25 INFO : sub dir2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2025/04/15 05:20:25 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2025/04/15 05:20:25 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dovuxej0zopu': Waiting for checks to finish 2025/04/15 05:20:25 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dovuxej0zopu': Waiting for transfers to finish 2025/04/15 05:20:27 DEBUG : sub dir/hello world: md5 = 27c489926a776be5f9e4f4653e2cd966 OK 2025/04/15 05:20:27 INFO : sub dir/hello world: Copied (new) 2025/04/15 05:20:27 INFO : sub dir/hello world: Deleted run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dovuxej0zopu'", Local "Local file system at /tmp/rclone1859944754", Modify Window "1ms" 2025/04/15 05:20:30 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestMoveEmptyDirectories (7.36s) === RUN TestSyncNoUpdateDirModtime run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dovuxej0zopu'", Local "Local file system at /tmp/rclone1859944754", Modify Window "1ms" 2025/04/15 05:20:31 DEBUG : sub dir no update dir modtime: Making directory with metadata 2025/04/15 05:20:31 INFO : sub dir no update dir modtime: Made directory with metadata (mtime=2001-02-03T04:05:06.499999999Z) 2025/04/15 05:20:32 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dovuxej0zopu': Waiting for checks to finish 2025/04/15 05:20:32 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dovuxej0zopu': Waiting for transfers to finish 2025/04/15 05:20:32 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dovuxej0zopu'", Local "Local file system at /tmp/rclone1859944754", Modify Window "1ms" --- PASS: TestSyncNoUpdateDirModtime (4.00s) === RUN TestMoveNoEmptyDirectories run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dovuxej0zopu'", Local "Local file system at /tmp/rclone1859944754", Modify Window "1ms" 2025/04/15 05:20:35 INFO : sub dir2: Making directory 2025/04/15 05:20:35 DEBUG : Added delayed dir = "sub dir", newDst= 2025/04/15 05:20:35 DEBUG : Added delayed dir = "sub dir2", newDst= 2025/04/15 05:20:35 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2025/04/15 05:20:35 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dovuxej0zopu': Waiting for checks to finish 2025/04/15 05:20:35 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dovuxej0zopu': Waiting for transfers to finish 2025/04/15 05:20:37 DEBUG : sub dir/hello world: md5 = abe608683ee111b6d71351eefbcfb1ed OK 2025/04/15 05:20:37 INFO : sub dir/hello world: Copied (new) 2025/04/15 05:20:37 INFO : sub dir/hello world: Deleted 2025/04/15 05:20:38 INFO : sub dir: Set directory modification time (using DirSetModTime) 2025/04/15 05:20:39 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestMoveNoEmptyDirectories (5.21s) === RUN TestSyncEmptyDirectories run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dovuxej0zopu'", Local "Local file system at /tmp/rclone1859944754", Modify Window "1ms" 2025/04/15 05:20:40 DEBUG : sub dir2: Making directory with metadata 2025/04/15 05:20:40 INFO : sub dir2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2025/04/15 05:20:40 INFO : sub dir: Set directory modification time (using DirSetModTime) 2025/04/15 05:20:40 DEBUG : sub dir: Making directory with metadata 2025/04/15 05:20:41 INFO : sub dir: Made directory with metadata (mtime=2001-02-03T04:05:06.499999999Z) 2025/04/15 05:20:41 DEBUG : sub dir2: Making directory with metadata 2025/04/15 05:20:42 INFO : sub dir2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2025/04/15 05:20:42 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2025/04/15 05:20:42 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dovuxej0zopu': Waiting for checks to finish 2025/04/15 05:20:42 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dovuxej0zopu': Waiting for transfers to finish 2025/04/15 05:20:43 DEBUG : sub dir/hello world: md5 = 0a684439a4d2a60f65400faa92d88667 OK 2025/04/15 05:20:43 INFO : sub dir/hello world: Copied (new) 2025/04/15 05:20:43 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dovuxej0zopu'", Local "Local file system at /tmp/rclone1859944754", Modify Window "1ms" 2025/04/15 05:20:46 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestSyncEmptyDirectories (7.29s) === RUN TestSyncSetDelayedModTimes run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dovuxej0zopu'", Local "Local file system at /tmp/rclone1859944754", Modify Window "1ms" sync_test.go:507: Backend doesn't have DirModTimeUpdatesOnWrite set --- SKIP: TestSyncSetDelayedModTimes (0.44s) === RUN TestSyncNoEmptyDirectories run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dovuxej0zopu'", Local "Local file system at /tmp/rclone1859944754", Modify Window "1ms" 2025/04/15 05:20:48 INFO : sub dir2: Making directory 2025/04/15 05:20:48 DEBUG : Added delayed dir = "sub dir", newDst= 2025/04/15 05:20:48 DEBUG : Added delayed dir = "sub dir2", newDst= 2025/04/15 05:20:48 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2025/04/15 05:20:48 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dovuxej0zopu': Waiting for checks to finish 2025/04/15 05:20:48 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dovuxej0zopu': Waiting for transfers to finish 2025/04/15 05:20:50 DEBUG : sub dir/hello world: md5 = 3975115c917552beeb6f586450b4c9db OK 2025/04/15 05:20:50 INFO : sub dir/hello world: Copied (new) 2025/04/15 05:20:50 DEBUG : Waiting for deletions to finish 2025/04/15 05:20:51 INFO : sub dir: Set directory modification time (using DirSetModTime) 2025/04/15 05:20:53 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestSyncNoEmptyDirectories (5.62s) === RUN TestServerSideCopy run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dovuxej0zopu'", Local "Local file system at /tmp/rclone1859944754", Modify Window "1ms" 2025/04/15 05:20:56 DEBUG : sub dir/hello world: md5 = 71eef68c3ee653d0b770e81489708651 OK 2025/04/15 05:20:56 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-hemeqat3dino" 2025/04/15 05:20:56 DEBUG : Creating backend with remote "TestDrive:crypt/rjlfmaqpceun6ri5r0o3b3drjuaun717ca9fvue5rehang5cg360" sync_test.go:590: Server side copy (if possible) Encrypted drive 'TestCryptDrive:rclone-test-dovuxej0zopu' -> Encrypted drive 'TestCryptDrive:rclone-test-hemeqat3dino' 2025/04/15 05:20:57 DEBUG : Added delayed dir = "sub dir", newDst= 2025/04/15 05:20:57 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2025/04/15 05:20:57 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hemeqat3dino': Waiting for checks to finish 2025/04/15 05:20:57 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hemeqat3dino': Waiting for transfers to finish 2025/04/15 05:21:00 INFO : sub dir/hello world: Copied (server-side copy) 2025/04/15 05:21:00 INFO : sub dir: Set directory modification time (using DirSetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dovuxej0zopu'", Local "Local file system at /tmp/rclone1859944754", Modify Window "1ms" 2025/04/15 05:21:01 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hemeqat3dino': Purge remote 2025/04/15 05:21:03 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestServerSideCopy (10.49s) === RUN TestCopyOverSelf run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dovuxej0zopu'", Local "Local file system at /tmp/rclone1859944754", Modify Window "1ms" 2025/04/15 05:21:06 DEBUG : sub dir/hello world: md5 = dc08a411af5495f53f8a3e8e36d92d37 OK 2025/04/15 05:21:07 INFO : sub dir: Set directory modification time (using SetModTime) 2025/04/15 05:21:07 DEBUG : Added delayed dir = "sub dir", newDst=sub dir 2025/04/15 05:21:07 DEBUG : sub dir/hello world: Sizes differ (src 17 vs dst 11) 2025/04/15 05:21:07 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dovuxej0zopu': Waiting for checks to finish 2025/04/15 05:21:07 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dovuxej0zopu': Waiting for transfers to finish 2025/04/15 05:21:09 DEBUG : sub dir/hello world: md5 = 6d370119f9cfb607897bd540328ef6e4 OK 2025/04/15 05:21:09 INFO : sub dir/hello world: Copied (replaced existing) 2025/04/15 05:21:09 INFO : sub dir: Set directory modification time (using SetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dovuxej0zopu'", Local "Local file system at /tmp/rclone1859944754", Modify Window "1ms" 2025/04/15 05:21:11 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestCopyOverSelf (8.52s) === RUN TestServerSideCopyOverSelf run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dovuxej0zopu'", Local "Local file system at /tmp/rclone1859944754", Modify Window "1ms" 2025/04/15 05:21:12 DEBUG : TestDrive: Loaded invalid token from config file - ignoring 2025/04/15 05:21:12 DEBUG : Saving config "token" in section "TestDrive" of the config file 2025/04/15 05:21:12 DEBUG : TestDrive: Saved new token in config file 2025/04/15 05:21:15 DEBUG : sub dir/hello world: md5 = ad9266546a3787362a26f9172d7df6af OK 2025/04/15 05:21:15 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-vomijox9beha" 2025/04/15 05:21:15 DEBUG : Creating backend with remote "TestDrive:crypt/4v5ldb28nfd7hcc0vrqfh8e2mf90qoof7ikbf1restt315fvrh40" sync_test.go:626: Server side copy (if possible) Encrypted drive 'TestCryptDrive:rclone-test-dovuxej0zopu' -> Encrypted drive 'TestCryptDrive:rclone-test-vomijox9beha' 2025/04/15 05:21:17 DEBUG : Added delayed dir = "sub dir", newDst= 2025/04/15 05:21:17 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2025/04/15 05:21:17 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vomijox9beha': Waiting for checks to finish 2025/04/15 05:21:17 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vomijox9beha': Waiting for transfers to finish 2025/04/15 05:21:19 INFO : sub dir/hello world: Copied (server-side copy) 2025/04/15 05:21:20 INFO : sub dir: Set directory modification time (using DirSetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dovuxej0zopu'", Local "Local file system at /tmp/rclone1859944754", Modify Window "1ms" 2025/04/15 05:21:22 DEBUG : sub dir/hello world: md5 = 14a55627cedb87f10295654d056ca7e9 OK 2025/04/15 05:21:23 DEBUG : sub dir: Directory modification time the same (differ by 0s, within tolerance 1ms) 2025/04/15 05:21:23 DEBUG : Added delayed dir = "sub dir", newDst=sub dir 2025/04/15 05:21:23 DEBUG : sub dir/hello world: Sizes differ (src 17 vs dst 11) 2025/04/15 05:21:23 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vomijox9beha': Waiting for checks to finish 2025/04/15 05:21:23 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vomijox9beha': Waiting for transfers to finish 2025/04/15 05:21:24 INFO : sub dir/hello world: Copied (server-side copy) 2025/04/15 05:21:25 INFO : sub dir: Set directory modification time (using SetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dovuxej0zopu'", Local "Local file system at /tmp/rclone1859944754", Modify Window "1ms" 2025/04/15 05:21:25 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vomijox9beha': Purge remote 2025/04/15 05:21:27 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestServerSideCopyOverSelf (16.29s) === RUN TestMoveOverSelf run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dovuxej0zopu'", Local "Local file system at /tmp/rclone1859944754", Modify Window "1ms" 2025/04/15 05:21:31 DEBUG : sub dir/hello world: md5 = 6244afff8bb6ae5c3130f8475a6ad156 OK 2025/04/15 05:21:32 INFO : sub dir: Set directory modification time (using SetModTime) 2025/04/15 05:21:32 DEBUG : Added delayed dir = "sub dir", newDst=sub dir 2025/04/15 05:21:32 DEBUG : sub dir/hello world: Sizes differ (src 17 vs dst 11) 2025/04/15 05:21:32 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dovuxej0zopu': Waiting for checks to finish 2025/04/15 05:21:32 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dovuxej0zopu': Waiting for transfers to finish 2025/04/15 05:21:34 DEBUG : sub dir/hello world: md5 = 35e4c49d58bbb26e27b0800cb2928977 OK 2025/04/15 05:21:34 INFO : sub dir/hello world: Copied (replaced existing) 2025/04/15 05:21:34 INFO : sub dir/hello world: Deleted 2025/04/15 05:21:34 INFO : sub dir: Set directory modification time (using SetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dovuxej0zopu'", Local "Local file system at /tmp/rclone1859944754", Modify Window "1ms" 2025/04/15 05:21:36 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestMoveOverSelf (8.27s) === RUN TestServerSideMoveOverSelf run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dovuxej0zopu'", Local "Local file system at /tmp/rclone1859944754", Modify Window "1ms" 2025/04/15 05:21:39 DEBUG : sub dir/hello world: md5 = aa37e8beac8362fbcec685e9fe236932 OK 2025/04/15 05:21:40 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-heraqur8giqe" 2025/04/15 05:21:40 DEBUG : Creating backend with remote "TestDrive:crypt/ohef9acuitspf9at9v8lf80n8tr82tsrr6k5ap95tpi1gh23ebtg" sync_test.go:671: Server side copy (if possible) Encrypted drive 'TestCryptDrive:rclone-test-dovuxej0zopu' -> Encrypted drive 'TestCryptDrive:rclone-test-heraqur8giqe' 2025/04/15 05:21:41 DEBUG : Added delayed dir = "sub dir", newDst= 2025/04/15 05:21:41 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2025/04/15 05:21:41 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-heraqur8giqe': Waiting for checks to finish 2025/04/15 05:21:41 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-heraqur8giqe': Waiting for transfers to finish 2025/04/15 05:21:44 INFO : sub dir/hello world: Copied (server-side copy) 2025/04/15 05:21:44 INFO : sub dir: Set directory modification time (using DirSetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dovuxej0zopu'", Local "Local file system at /tmp/rclone1859944754", Modify Window "1ms" 2025/04/15 05:21:46 DEBUG : sub dir/hello world: md5 = 693f4f43b2dda4038196f3024b030273 OK 2025/04/15 05:21:47 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-heraqur8giqe': Using server-side directory move 2025/04/15 05:21:47 INFO : Encrypted drive 'TestCryptDrive:rclone-test-heraqur8giqe': Server side directory move failed - fallback to file moves: can't copy directory - destination already exists 2025/04/15 05:21:47 DEBUG : sub dir: Directory modification time the same (differ by 0s, within tolerance 1ms) 2025/04/15 05:21:47 DEBUG : Added delayed dir = "sub dir", newDst=sub dir 2025/04/15 05:21:47 DEBUG : sub dir/hello world: Sizes differ (src 17 vs dst 11) 2025/04/15 05:21:47 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-heraqur8giqe': Waiting for checks to finish 2025/04/15 05:21:47 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-heraqur8giqe': Waiting for transfers to finish 2025/04/15 05:21:48 INFO : sub dir/hello world: Deleted 2025/04/15 05:21:48 INFO : sub dir/hello world: Moved (server-side) 2025/04/15 05:21:49 INFO : sub dir: Set directory modification time (using SetModTime) 2025/04/15 05:21:51 DEBUG : sub dir/hello world: md5 = 7e847f214155072156480e293e02fe59 OK 2025/04/15 05:21:51 DEBUG : testing file moves 2025/04/15 05:21:52 DEBUG : sub dir: Directory modification time the same (differ by 0s, within tolerance 1ms) 2025/04/15 05:21:52 DEBUG : Added delayed dir = "sub dir", newDst=sub dir 2025/04/15 05:21:52 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-heraqur8giqe': Waiting for checks to finish 2025/04/15 05:21:52 DEBUG : sub dir/hello world: Sizes differ (src 24 vs dst 17) 2025/04/15 05:21:52 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-heraqur8giqe': Waiting for transfers to finish 2025/04/15 05:21:52 INFO : sub dir/hello world: Deleted 2025/04/15 05:21:53 INFO : sub dir/hello world: Moved (server-side) 2025/04/15 05:21:53 INFO : sub dir: Set directory modification time (using SetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dovuxej0zopu'", Local "Local file system at /tmp/rclone1859944754", Modify Window "1ms" 2025/04/15 05:21:54 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-heraqur8giqe': Purge remote --- PASS: TestServerSideMoveOverSelf (20.20s) === RUN TestCopyAfterDelete run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dovuxej0zopu'", Local "Local file system at /tmp/rclone1859944754", Modify Window "1ms" 2025/04/15 05:21:59 DEBUG : sub dir/hello world: md5 = 438a1ec196dfa5620082675b4c34e627 OK 2025/04/15 05:21:59 ERROR : : error listing: directory not found 2025/04/15 05:22:00 INFO : Local file system at /tmp/rclone1859944754: Making directory 2025/04/15 05:22:00 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dovuxej0zopu': Waiting for checks to finish 2025/04/15 05:22:00 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dovuxej0zopu': Waiting for transfers to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dovuxej0zopu'", Local "Local file system at /tmp/rclone1859944754", Modify Window "1ms" 2025/04/15 05:22:02 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestCopyAfterDelete (5.88s) === RUN TestCopyRedownload run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dovuxej0zopu'", Local "Local file system at /tmp/rclone1859944754", Modify Window "1ms" 2025/04/15 05:22:05 DEBUG : sub dir/hello world: md5 = f60c302df452a59cdd5f4952f22c41ea OK 2025/04/15 05:22:06 DEBUG : Added delayed dir = "sub dir", newDst= 2025/04/15 05:22:06 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2025/04/15 05:22:06 DEBUG : Local file system at /tmp/rclone1859944754: Waiting for checks to finish 2025/04/15 05:22:06 DEBUG : Local file system at /tmp/rclone1859944754: Waiting for transfers to finish 2025/04/15 05:22:07 DEBUG : sub dir/hello world.285f0a30.partial: renamed to: sub dir/hello world 2025/04/15 05:22:07 INFO : sub dir/hello world: Copied (new) 2025/04/15 05:22:07 INFO : sub dir: Set directory modification time (using DirSetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dovuxej0zopu'", Local "Local file system at /tmp/rclone1859944754", Modify Window "1ms" 2025/04/15 05:22:08 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestCopyRedownload (6.53s) === RUN TestSyncBasedOnCheckSum run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dovuxej0zopu'", Local "Local file system at /tmp/rclone1859944754", Modify Window "1ms" 2025/04/15 05:22:10 DEBUG : check sum: Need to transfer - File not found at Destination 2025/04/15 05:22:10 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dovuxej0zopu': Waiting for checks to finish 2025/04/15 05:22:10 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dovuxej0zopu': Waiting for transfers to finish 2025/04/15 05:22:11 DEBUG : check sum: md5 = bb86217af7075986b4dde84c91664752 OK 2025/04/15 05:22:11 INFO : check sum: Copied (new) 2025/04/15 05:22:11 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dovuxej0zopu'", Local "Local file system at /tmp/rclone1859944754", Modify Window "1ms" 2025/04/15 05:22:12 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dovuxej0zopu': Waiting for checks to finish 2025/04/15 05:22:12 NOTICE: Encrypted drive 'TestCryptDrive:rclone-test-dovuxej0zopu': --checksum is in use but the source and destination have no hashes in common; falling back to --size-only 2025/04/15 05:22:12 DEBUG : check sum: Size of src and dst objects identical 2025/04/15 05:22:12 DEBUG : check sum: Unchanged skipping 2025/04/15 05:22:12 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dovuxej0zopu': Waiting for transfers to finish 2025/04/15 05:22:12 DEBUG : Waiting for deletions to finish 2025/04/15 05:22:12 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dovuxej0zopu'", Local "Local file system at /tmp/rclone1859944754", Modify Window "1ms" --- PASS: TestSyncBasedOnCheckSum (4.19s) === RUN TestSyncSizeOnly run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dovuxej0zopu'", Local "Local file system at /tmp/rclone1859944754", Modify Window "1ms" 2025/04/15 05:22:14 DEBUG : sizeonly: Need to transfer - File not found at Destination 2025/04/15 05:22:14 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dovuxej0zopu': Waiting for checks to finish 2025/04/15 05:22:14 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dovuxej0zopu': Waiting for transfers to finish 2025/04/15 05:22:15 DEBUG : sizeonly: md5 = b04132a35a01e2c9943dc7c4f5ec2635 OK 2025/04/15 05:22:15 INFO : sizeonly: Copied (new) 2025/04/15 05:22:15 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dovuxej0zopu'", Local "Local file system at /tmp/rclone1859944754", Modify Window "1ms" 2025/04/15 05:22:16 DEBUG : sizeonly: Sizes identical 2025/04/15 05:22:16 DEBUG : sizeonly: Unchanged skipping 2025/04/15 05:22:16 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dovuxej0zopu': Waiting for checks to finish 2025/04/15 05:22:16 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dovuxej0zopu': Waiting for transfers to finish 2025/04/15 05:22:16 DEBUG : Waiting for deletions to finish 2025/04/15 05:22:16 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dovuxej0zopu'", Local "Local file system at /tmp/rclone1859944754", Modify Window "1ms" --- PASS: TestSyncSizeOnly (4.38s) === RUN TestSyncIgnoreSize run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dovuxej0zopu'", Local "Local file system at /tmp/rclone1859944754", Modify Window "1ms" 2025/04/15 05:22:18 DEBUG : ignore-size: Need to transfer - File not found at Destination 2025/04/15 05:22:18 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dovuxej0zopu': Waiting for checks to finish 2025/04/15 05:22:18 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dovuxej0zopu': Waiting for transfers to finish 2025/04/15 05:22:20 DEBUG : ignore-size: md5 = 6a264578c93c2aeba3486a2f29a272a2 OK 2025/04/15 05:22:20 INFO : ignore-size: Copied (new) 2025/04/15 05:22:20 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dovuxej0zopu'", Local "Local file system at /tmp/rclone1859944754", Modify Window "1ms" 2025/04/15 05:22:21 DEBUG : ignore-size: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/15 05:22:21 DEBUG : ignore-size: Unchanged skipping 2025/04/15 05:22:21 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dovuxej0zopu': Waiting for checks to finish 2025/04/15 05:22:21 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dovuxej0zopu': Waiting for transfers to finish 2025/04/15 05:22:21 DEBUG : Waiting for deletions to finish 2025/04/15 05:22:21 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dovuxej0zopu'", Local "Local file system at /tmp/rclone1859944754", Modify Window "1ms" --- PASS: TestSyncIgnoreSize (5.11s) === RUN TestSyncIgnoreTimes run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dovuxej0zopu'", Local "Local file system at /tmp/rclone1859944754", Modify Window "1ms" 2025/04/15 05:22:24 DEBUG : existing: md5 = 238bf150bbcb931677b522571b83dacd OK 2025/04/15 05:22:25 DEBUG : existing: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/15 05:22:25 DEBUG : existing: Unchanged skipping 2025/04/15 05:22:25 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dovuxej0zopu': Waiting for checks to finish 2025/04/15 05:22:25 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dovuxej0zopu': Waiting for transfers to finish 2025/04/15 05:22:25 DEBUG : Waiting for deletions to finish 2025/04/15 05:22:25 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dovuxej0zopu'", Local "Local file system at /tmp/rclone1859944754", Modify Window "1ms" 2025/04/15 05:22:25 DEBUG : existing: Transferring unconditionally as --ignore-times is in use 2025/04/15 05:22:25 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dovuxej0zopu': Waiting for checks to finish 2025/04/15 05:22:25 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dovuxej0zopu': Waiting for transfers to finish 2025/04/15 05:22:26 DEBUG : existing: md5 = a8fe336818d958cb4c80ef8e1cf48795 OK 2025/04/15 05:22:26 INFO : existing: Copied (replaced existing) 2025/04/15 05:22:26 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dovuxej0zopu'", Local "Local file system at /tmp/rclone1859944754", Modify Window "1ms" --- PASS: TestSyncIgnoreTimes (5.16s) === RUN TestSyncIgnoreExisting run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dovuxej0zopu'", Local "Local file system at /tmp/rclone1859944754", Modify Window "1ms" 2025/04/15 05:22:29 DEBUG : existing: Need to transfer - File not found at Destination 2025/04/15 05:22:29 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dovuxej0zopu': Waiting for checks to finish 2025/04/15 05:22:29 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dovuxej0zopu': Waiting for transfers to finish 2025/04/15 05:22:30 DEBUG : existing: md5 = 5965c1c45c56cb4c206b52acace20ee6 OK 2025/04/15 05:22:30 INFO : existing: Copied (new) 2025/04/15 05:22:30 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dovuxej0zopu'", Local "Local file system at /tmp/rclone1859944754", Modify Window "1ms" 2025/04/15 05:22:30 DEBUG : existing: Destination exists, skipping 2025/04/15 05:22:30 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dovuxej0zopu': Waiting for checks to finish 2025/04/15 05:22:30 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dovuxej0zopu': Waiting for transfers to finish 2025/04/15 05:22:30 DEBUG : Waiting for deletions to finish 2025/04/15 05:22:30 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dovuxej0zopu'", Local "Local file system at /tmp/rclone1859944754", Modify Window "1ms" --- PASS: TestSyncIgnoreExisting (4.16s) === RUN TestSyncIgnoreErrors run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dovuxej0zopu'", Local "Local file system at /tmp/rclone1859944754", Modify Window "1ms" 2025/04/15 05:22:35 DEBUG : b/potato: md5 = c07bf5050bc4b8939a38d31ec96b85e8 OK 2025/04/15 05:22:37 DEBUG : c/non empty space: md5 = ecfab238a0db7c9170a7181c8b7fb2f0 OK 2025/04/15 05:22:37 INFO : d: Making directory 2025/04/15 05:22:39 DEBUG : Added delayed dir = "a", newDst= 2025/04/15 05:22:39 INFO : c: Set directory modification time (using SetModTime) 2025/04/15 05:22:39 DEBUG : Added delayed dir = "c", newDst=c 2025/04/15 05:22:39 DEBUG : a/potato2: Need to transfer - File not found at Destination 2025/04/15 05:22:39 DEBUG : c/non empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/04/15 05:22:39 DEBUG : c/non empty space: Unchanged skipping 2025/04/15 05:22:39 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dovuxej0zopu': Waiting for checks to finish 2025/04/15 05:22:39 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dovuxej0zopu': Waiting for transfers to finish 2025/04/15 05:22:41 DEBUG : a/potato2: md5 = d36a54a2ec7d18cca36cc1e4d3783cd3 OK 2025/04/15 05:22:41 INFO : a/potato2: Copied (new) 2025/04/15 05:22:41 DEBUG : Waiting for deletions to finish 2025/04/15 05:22:42 INFO : b/potato: Deleted 2025/04/15 05:22:42 INFO : a: Set directory modification time (using DirSetModTime) 2025/04/15 05:22:42 INFO : d: Removing directory 2025/04/15 05:22:43 INFO : b: Removing directory 2025/04/15 05:22:43 DEBUG : 32d8ua6196mc1r7qkfog53rkg0: Rmdir: contains trashed file: "2m507n64kafsi59v9q71r281a4" 2025/04/15 05:22:44 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dovuxej0zopu': deleted 2 directories run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dovuxej0zopu'", Local "Local file system at /tmp/rclone1859944754", Modify Window "1ms" 2025/04/15 05:22:46 DEBUG : 3i9du405pfogq3ncai6pg7ouio: Rmdir: contains trashed file: "982d3pss7t5pn0il16r2foj31s" 2025/04/15 05:22:47 DEBUG : 2bsvlrk2ne1lfitm6tttcu0qt8: Rmdir: contains trashed file: "89l8renevh3mji1c8r1p7qn6tg" --- PASS: TestSyncIgnoreErrors (15.23s) === RUN TestSyncAfterChangingModtimeOnly run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dovuxej0zopu'", Local "Local file system at /tmp/rclone1859944754", Modify Window "1ms" 2025/04/15 05:22:49 DEBUG : empty space: md5 = 2d03c7fc9631c75e3ace3409faea730b OK 2025/04/15 05:22:50 DEBUG : empty space: Modification times differ by -95456h54m52.624456789s: 2011-12-25 12:59:59.123456789 +0000 UTC, 2001-02-03 04:05:06.499 +0000 UTC 2025/04/15 05:22:50 NOTICE: empty space: Skipped copy as --dry-run is set (size 1) 2025/04/15 05:22:50 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dovuxej0zopu': Waiting for checks to finish 2025/04/15 05:22:50 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dovuxej0zopu': Waiting for transfers to finish 2025/04/15 05:22:50 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dovuxej0zopu'", Local "Local file system at /tmp/rclone1859944754", Modify Window "1ms" 2025/04/15 05:22:50 DEBUG : empty space: Modification times differ by -95456h54m52.624456789s: 2011-12-25 12:59:59.123456789 +0000 UTC, 2001-02-03 04:05:06.499 +0000 UTC 2025/04/15 05:22:50 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dovuxej0zopu': Waiting for checks to finish 2025/04/15 05:22:50 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dovuxej0zopu': Waiting for transfers to finish 2025/04/15 05:22:51 DEBUG : empty space: md5 = fc403b7b1fc4f2886316f195538b48af OK 2025/04/15 05:22:51 INFO : empty space: Copied (replaced existing) 2025/04/15 05:22:51 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dovuxej0zopu'", Local "Local file system at /tmp/rclone1859944754", Modify Window "1ms" --- PASS: TestSyncAfterChangingModtimeOnly (6.78s) === RUN TestSyncAfterChangingModtimeOnlyWithNoUpdateModTime run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dovuxej0zopu'", Local "Local file system at /tmp/rclone1859944754", 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-dovuxej0zopu'", Local "Local file system at /tmp/rclone1859944754", Modify Window "1ms" 2025/04/15 05:22:56 DEBUG : foo: md5 = 8b5b586d4fabc66eecb3c597d94acf56 OK 2025/04/15 05:22:57 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dovuxej0zopu': Waiting for checks to finish 2025/04/15 05:22:57 DEBUG : foo: Modification times differ by -95456h54m52.624456789s: 2011-12-25 12:59:59.123456789 +0000 UTC, 2001-02-03 04:05:06.499 +0000 UTC 2025/04/15 05:22:57 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dovuxej0zopu': Waiting for transfers to finish 2025/04/15 05:22:58 DEBUG : foo: md5 = f033b38067fae25901e280a0be4dfbc4 OK 2025/04/15 05:22:58 INFO : foo: Copied (replaced existing) 2025/04/15 05:22:58 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dovuxej0zopu'", Local "Local file system at /tmp/rclone1859944754", Modify Window "1ms" --- PASS: TestSyncDoesntUpdateModtime (4.75s) === RUN TestSyncAfterAddingAFile run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dovuxej0zopu'", Local "Local file system at /tmp/rclone1859944754", Modify Window "1ms" 2025/04/15 05:23:01 DEBUG : empty space: md5 = 2224cc61ad414f2958e3168ab7686d41 OK 2025/04/15 05:23:02 DEBUG : potato: Need to transfer - File not found at Destination 2025/04/15 05:23:02 DEBUG : empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/04/15 05:23:02 DEBUG : empty space: Unchanged skipping 2025/04/15 05:23:02 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dovuxej0zopu': Waiting for checks to finish 2025/04/15 05:23:02 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dovuxej0zopu': Waiting for transfers to finish 2025/04/15 05:23:03 DEBUG : potato: md5 = 3e7c92f7438d3de3f990e7dc97c3a598 OK 2025/04/15 05:23:03 INFO : potato: Copied (new) 2025/04/15 05:23:03 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dovuxej0zopu'", Local "Local file system at /tmp/rclone1859944754", Modify Window "1ms" --- PASS: TestSyncAfterAddingAFile (5.35s) === RUN TestSyncAfterChangingFilesSizeOnly run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dovuxej0zopu'", Local "Local file system at /tmp/rclone1859944754", Modify Window "1ms" 2025/04/15 05:23:06 DEBUG : potato: md5 = 4ea1c2977de74daad8fb806dfef89843 OK 2025/04/15 05:23:07 DEBUG : potato: Sizes differ (src 21 vs dst 60) 2025/04/15 05:23:07 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dovuxej0zopu': Waiting for checks to finish 2025/04/15 05:23:07 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dovuxej0zopu': Waiting for transfers to finish 2025/04/15 05:23:17 DEBUG : potato: md5 = 649c40386aa8e58b1bf9cb415fd5ee42 OK 2025/04/15 05:23:17 INFO : potato: Copied (replaced existing) 2025/04/15 05:23:17 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dovuxej0zopu'", Local "Local file system at /tmp/rclone1859944754", Modify Window "1ms" --- PASS: TestSyncAfterChangingFilesSizeOnly (13.07s) === RUN TestSyncAfterChangingContentsOnly run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dovuxej0zopu'", Local "Local file system at /tmp/rclone1859944754", Modify Window "1ms" 2025/04/15 05:23:20 DEBUG : potato: md5 = ba6901c2bb41bb0b1b9afdc6c613a5e0 OK 2025/04/15 05:23:20 DEBUG : potato: Modification times differ by 119h59m59.876543211s: 2011-12-25 12:59:59.123456789 +0000 UTC, 2011-12-30 12:59:59 +0000 UTC 2025/04/15 05:23:20 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dovuxej0zopu': Waiting for checks to finish 2025/04/15 05:23:20 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dovuxej0zopu': Waiting for transfers to finish 2025/04/15 05:23:21 DEBUG : potato: md5 = af4c0a739bafb25125e4d0b61b6dd9ab OK 2025/04/15 05:23:21 INFO : potato: Copied (replaced existing) 2025/04/15 05:23:21 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dovuxej0zopu'", Local "Local file system at /tmp/rclone1859944754", Modify Window "1ms" --- PASS: TestSyncAfterChangingContentsOnly (4.76s) === RUN TestSyncAfterRemovingAFileAndAddingAFileDryRun run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dovuxej0zopu'", Local "Local file system at /tmp/rclone1859944754", Modify Window "1ms" 2025/04/15 05:23:24 DEBUG : potato: md5 = 929b541f3a5f127a7747a9cd05116a81 OK 2025/04/15 05:23:26 DEBUG : empty space: md5 = 7b6ffddeedc8918fc860192879882183 OK 2025/04/15 05:23:26 DEBUG : potato2: Need to transfer - File not found at Destination 2025/04/15 05:23:26 NOTICE: potato2: Skipped copy as --dry-run is set (size 60) 2025/04/15 05:23:26 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dovuxej0zopu': Waiting for checks to finish 2025/04/15 05:23:26 DEBUG : empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/04/15 05:23:26 DEBUG : empty space: Unchanged skipping 2025/04/15 05:23:26 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dovuxej0zopu': Waiting for transfers to finish 2025/04/15 05:23:26 DEBUG : Waiting for deletions to finish 2025/04/15 05:23:26 NOTICE: potato: Skipped delete as --dry-run is set (size 21) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dovuxej0zopu'", Local "Local file system at /tmp/rclone1859944754", Modify Window "1ms" --- PASS: TestSyncAfterRemovingAFileAndAddingAFileDryRun (4.95s) === RUN TestSyncAfterRemovingAFileAndAddingAFile run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dovuxej0zopu'", Local "Local file system at /tmp/rclone1859944754", Modify Window "1ms" 2025/04/15 05:23:30 DEBUG : potato: md5 = a2451a201b0d0827b19d09c5b3a81276 OK 2025/04/15 05:23:31 DEBUG : empty space: md5 = 29367e2196d6a650c371bdc47427ca93 OK 2025/04/15 05:23:31 DEBUG : potato2: Need to transfer - File not found at Destination 2025/04/15 05:23:31 DEBUG : empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/04/15 05:23:31 DEBUG : empty space: Unchanged skipping 2025/04/15 05:23:31 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dovuxej0zopu': Waiting for checks to finish 2025/04/15 05:23:31 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dovuxej0zopu': Waiting for transfers to finish 2025/04/15 05:23:33 DEBUG : potato2: md5 = 698cd5f1be31bbfa5c55a94eac04aec8 OK 2025/04/15 05:23:33 INFO : potato2: Copied (new) 2025/04/15 05:23:33 DEBUG : Waiting for deletions to finish 2025/04/15 05:23:33 INFO : potato: Deleted run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dovuxej0zopu'", Local "Local file system at /tmp/rclone1859944754", Modify Window "1ms" --- PASS: TestSyncAfterRemovingAFileAndAddingAFile (7.35s) === RUN TestSyncAfterRemovingAFileAndAddingAFileSubDir run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dovuxej0zopu'", Local "Local file system at /tmp/rclone1859944754", Modify Window "1ms" 2025/04/15 05:23:37 DEBUG : b/potato: md5 = 24ca3942ecc69f7f72aaf338490cbe3a OK 2025/04/15 05:23:40 DEBUG : c/non empty space: md5 = 317a464644b506be9d007a33649fb1fd OK 2025/04/15 05:23:40 INFO : d: Making directory 2025/04/15 05:23:40 INFO : d/e: Making directory 2025/04/15 05:23:42 DEBUG : Added delayed dir = "a", newDst= 2025/04/15 05:23:43 INFO : c: Set directory modification time (using SetModTime) 2025/04/15 05:23:43 DEBUG : Added delayed dir = "c", newDst=c 2025/04/15 05:23:43 DEBUG : c/non empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/04/15 05:23:43 DEBUG : a/potato2: Need to transfer - File not found at Destination 2025/04/15 05:23:43 DEBUG : c/non empty space: Unchanged skipping 2025/04/15 05:23:43 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dovuxej0zopu': Waiting for checks to finish 2025/04/15 05:23:43 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dovuxej0zopu': Waiting for transfers to finish 2025/04/15 05:23:45 DEBUG : a/potato2: md5 = f86f0fb823023307ed83ce901b17ca11 OK 2025/04/15 05:23:45 INFO : a/potato2: Copied (new) 2025/04/15 05:23:45 DEBUG : Waiting for deletions to finish 2025/04/15 05:23:46 INFO : b/potato: Deleted 2025/04/15 05:23:46 INFO : a: Set directory modification time (using DirSetModTime) 2025/04/15 05:23:46 INFO : d/e: Removing directory 2025/04/15 05:23:47 INFO : d: Removing directory 2025/04/15 05:23:47 DEBUG : ka6id8d20d3s5ktapedlphgta8: Rmdir: contains trashed file: "r8sppajuabeak3sbgj2ak8vuf8" 2025/04/15 05:23:48 INFO : b: Removing directory 2025/04/15 05:23:48 DEBUG : 32d8ua6196mc1r7qkfog53rkg0: Rmdir: contains trashed file: "2m507n64kafsi59v9q71r281a4" 2025/04/15 05:23:48 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dovuxej0zopu': deleted 3 directories run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dovuxej0zopu'", Local "Local file system at /tmp/rclone1859944754", Modify Window "1ms" 2025/04/15 05:23:50 DEBUG : 3i9du405pfogq3ncai6pg7ouio: Rmdir: contains trashed file: "982d3pss7t5pn0il16r2foj31s" 2025/04/15 05:23:51 DEBUG : 2bsvlrk2ne1lfitm6tttcu0qt8: Rmdir: contains trashed file: "89l8renevh3mji1c8r1p7qn6tg" --- PASS: TestSyncAfterRemovingAFileAndAddingAFileSubDir (16.92s) === RUN TestSyncAfterRemovingAFileAndAddingAFileSubDirWithErrors run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dovuxej0zopu'", Local "Local file system at /tmp/rclone1859944754", Modify Window "1ms" 2025/04/15 05:23:54 DEBUG : b/potato: md5 = 19c6553bca2f21a3823c9f07e7d0f655 OK 2025/04/15 05:23:56 DEBUG : c/non empty space: md5 = f60bc63c452164702cb5ba11aa130f46 OK 2025/04/15 05:23:56 INFO : d: Making directory 2025/04/15 05:23:58 DEBUG : Added delayed dir = "a", newDst= 2025/04/15 05:23:59 INFO : c: Set directory modification time (using SetModTime) 2025/04/15 05:23:59 DEBUG : Added delayed dir = "c", newDst=c 2025/04/15 05:23:59 DEBUG : c/non empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/04/15 05:23:59 DEBUG : a/potato2: Need to transfer - File not found at Destination 2025/04/15 05:23:59 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dovuxej0zopu': Waiting for checks to finish 2025/04/15 05:23:59 DEBUG : c/non empty space: Unchanged skipping 2025/04/15 05:23:59 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dovuxej0zopu': Waiting for transfers to finish 2025/04/15 05:24:01 DEBUG : a/potato2: md5 = 80872f92e33af08639ae2f33ccd8f30f OK 2025/04/15 05:24:01 INFO : a/potato2: Copied (new) 2025/04/15 05:24:01 ERROR : Encrypted drive 'TestCryptDrive:rclone-test-dovuxej0zopu': not deleting files as there were IO errors 2025/04/15 05:24:01 INFO : a: Set directory modification time (using DirSetModTime) 2025/04/15 05:24:01 ERROR : Encrypted drive 'TestCryptDrive:rclone-test-dovuxej0zopu': not deleting directories as there were IO errors run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dovuxej0zopu'", Local "Local file system at /tmp/rclone1859944754", Modify Window "1ms" 2025/04/15 05:24:04 DEBUG : 3i9du405pfogq3ncai6pg7ouio: Rmdir: contains trashed file: "982d3pss7t5pn0il16r2foj31s" 2025/04/15 05:24:05 DEBUG : 32d8ua6196mc1r7qkfog53rkg0: Rmdir: contains trashed file: "2m507n64kafsi59v9q71r281a4" 2025/04/15 05:24:06 DEBUG : 2bsvlrk2ne1lfitm6tttcu0qt8: Rmdir: contains trashed file: "89l8renevh3mji1c8r1p7qn6tg" --- PASS: TestSyncAfterRemovingAFileAndAddingAFileSubDirWithErrors (14.84s) === RUN TestSyncDeleteAfter --- PASS: TestSyncDeleteAfter (0.00s) === RUN TestSyncDeleteDuring run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dovuxej0zopu'", Local "Local file system at /tmp/rclone1859944754", Modify Window "1ms" 2025/04/15 05:24:08 DEBUG : potato: md5 = c0ba1c267ea0e27d8dca75537cbb4a42 OK 2025/04/15 05:24:10 DEBUG : empty space: md5 = 996896d23233a03d0ad7799495102e56 OK 2025/04/15 05:24:10 DEBUG : Waiting for deletions to finish 2025/04/15 05:24:10 DEBUG : empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/04/15 05:24:10 DEBUG : potato2: Need to transfer - File not found at Destination 2025/04/15 05:24:10 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dovuxej0zopu': Waiting for checks to finish 2025/04/15 05:24:10 DEBUG : empty space: Unchanged skipping 2025/04/15 05:24:10 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dovuxej0zopu': Waiting for transfers to finish 2025/04/15 05:24:11 INFO : potato: Deleted 2025/04/15 05:24:12 DEBUG : potato2: md5 = a980d7f7947f7c733630b6d6da5b31e2 OK 2025/04/15 05:24:12 INFO : potato2: Copied (new) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dovuxej0zopu'", Local "Local file system at /tmp/rclone1859944754", Modify Window "1ms" --- PASS: TestSyncDeleteDuring (6.83s) === RUN TestSyncDeleteBefore run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dovuxej0zopu'", Local "Local file system at /tmp/rclone1859944754", Modify Window "1ms" 2025/04/15 05:24:15 DEBUG : potato: md5 = 78538b869aa4ff226ff1f796d9565469 OK 2025/04/15 05:24:17 DEBUG : empty space: md5 = fc803a078a8c40652b126b28ca68dd7d OK 2025/04/15 05:24:17 DEBUG : Waiting for deletions to finish 2025/04/15 05:24:17 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dovuxej0zopu': Waiting for checks to finish 2025/04/15 05:24:17 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dovuxej0zopu': Waiting for transfers to finish 2025/04/15 05:24:18 INFO : potato: Deleted 2025/04/15 05:24:18 DEBUG : empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/04/15 05:24:18 DEBUG : potato2: Need to transfer - File not found at Destination 2025/04/15 05:24:18 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dovuxej0zopu': Waiting for checks to finish 2025/04/15 05:24:18 DEBUG : empty space: Unchanged skipping 2025/04/15 05:24:18 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dovuxej0zopu': Waiting for transfers to finish 2025/04/15 05:24:19 DEBUG : potato2: md5 = 870d02aeb6a4c07fc382b33669f2b9a4 OK 2025/04/15 05:24:19 INFO : potato2: Copied (new) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dovuxej0zopu'", Local "Local file system at /tmp/rclone1859944754", Modify Window "1ms" --- PASS: TestSyncDeleteBefore (7.31s) === RUN TestCopyDeleteBefore run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dovuxej0zopu'", Local "Local file system at /tmp/rclone1859944754", Modify Window "1ms" 2025/04/15 05:24:23 DEBUG : potato: md5 = a1882dc1250ff51eed85aa3acc2fff26 OK 2025/04/15 05:24:23 DEBUG : potato2: Need to transfer - File not found at Destination 2025/04/15 05:24:23 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dovuxej0zopu': Waiting for checks to finish 2025/04/15 05:24:23 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dovuxej0zopu': Waiting for transfers to finish 2025/04/15 05:24:25 DEBUG : potato2: md5 = dc30e6a1f01354079a84a51959c05b42 OK 2025/04/15 05:24:25 INFO : potato2: Copied (new) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dovuxej0zopu'", Local "Local file system at /tmp/rclone1859944754", Modify Window "1ms" --- PASS: TestCopyDeleteBefore (5.55s) === RUN TestSyncWithExclude run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dovuxej0zopu'", Local "Local file system at /tmp/rclone1859944754", Modify Window "1ms" 2025/04/15 05:24:29 DEBUG : potato2: md5 = b10273ee3bed90050ab9534a7d9eee2d OK 2025/04/15 05:24:30 DEBUG : empty space: md5 = 95138597c9d2a306f38412acc9ca3328 OK 2025/04/15 05:24:30 DEBUG : enormous: Excluded (Size Filter) 2025/04/15 05:24:30 DEBUG : enormous: Excluded 2025/04/15 05:24:30 DEBUG : potato2: Excluded (Size Filter) 2025/04/15 05:24:30 DEBUG : potato2: Excluded 2025/04/15 05:24:31 DEBUG : potato2: Excluded (Size Filter) 2025/04/15 05:24:31 DEBUG : empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/04/15 05:24:31 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dovuxej0zopu': Waiting for checks to finish 2025/04/15 05:24:31 DEBUG : empty space: Unchanged skipping 2025/04/15 05:24:31 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dovuxej0zopu': Waiting for transfers to finish 2025/04/15 05:24:31 DEBUG : Waiting for deletions to finish 2025/04/15 05:24:31 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dovuxej0zopu'", Local "Local file system at /tmp/rclone1859944754", Modify Window "1ms" 2025/04/15 05:24:31 DEBUG : enormous: Excluded (Size Filter) 2025/04/15 05:24:31 DEBUG : enormous: Excluded 2025/04/15 05:24:31 DEBUG : potato2: Excluded (Size Filter) 2025/04/15 05:24:31 DEBUG : potato2: Excluded 2025/04/15 05:24:31 DEBUG : potato2: Excluded (Size Filter) 2025/04/15 05:24:31 DEBUG : empty space: Size and modification time the same (differ by 456.789µs, within tolerance 1ms) 2025/04/15 05:24:31 DEBUG : empty space: Unchanged skipping 2025/04/15 05:24:31 DEBUG : Local file system at /tmp/rclone1859944754: Waiting for checks to finish 2025/04/15 05:24:31 DEBUG : Local file system at /tmp/rclone1859944754: Waiting for transfers to finish 2025/04/15 05:24:31 DEBUG : Waiting for deletions to finish 2025/04/15 05:24:31 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dovuxej0zopu'", Local "Local file system at /tmp/rclone1859944754", Modify Window "1ms" --- PASS: TestSyncWithExclude (6.59s) === RUN TestSyncWithExcludeAndDeleteExcluded run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dovuxej0zopu'", Local "Local file system at /tmp/rclone1859944754", Modify Window "1ms" 2025/04/15 05:24:35 DEBUG : potato2: md5 = 189840c087665ab2168ab9cc9402f177 OK 2025/04/15 05:24:36 DEBUG : empty space: md5 = 5a60a4fa2588e2fc219d7eedac372fe7 OK 2025/04/15 05:24:38 DEBUG : enormous: md5 = 85c695a49d3fd3fa86af3199fb23bab3 OK 2025/04/15 05:24:38 DEBUG : enormous: Excluded (Size Filter) 2025/04/15 05:24:38 DEBUG : enormous: Excluded 2025/04/15 05:24:38 DEBUG : potato2: Excluded (Size Filter) 2025/04/15 05:24:38 DEBUG : potato2: Excluded 2025/04/15 05:24:38 DEBUG : empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/04/15 05:24:38 DEBUG : empty space: Unchanged skipping 2025/04/15 05:24:38 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dovuxej0zopu': Waiting for checks to finish 2025/04/15 05:24:38 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dovuxej0zopu': Waiting for transfers to finish 2025/04/15 05:24:38 DEBUG : Waiting for deletions to finish 2025/04/15 05:24:39 INFO : potato2: Deleted 2025/04/15 05:24:39 INFO : enormous: Deleted 2025/04/15 05:24:39 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dovuxej0zopu'", Local "Local file system at /tmp/rclone1859944754", Modify Window "1ms" 2025/04/15 05:24:39 DEBUG : empty space: Size and modification time the same (differ by 456.789µs, within tolerance 1ms) 2025/04/15 05:24:39 DEBUG : Local file system at /tmp/rclone1859944754: Waiting for checks to finish 2025/04/15 05:24:39 DEBUG : empty space: Unchanged skipping 2025/04/15 05:24:39 DEBUG : Local file system at /tmp/rclone1859944754: Waiting for transfers to finish 2025/04/15 05:24:39 DEBUG : Waiting for deletions to finish 2025/04/15 05:24:39 INFO : enormous: Deleted 2025/04/15 05:24:39 INFO : potato2: Deleted 2025/04/15 05:24:39 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dovuxej0zopu'", Local "Local file system at /tmp/rclone1859944754", Modify Window "1ms" --- PASS: TestSyncWithExcludeAndDeleteExcluded (7.75s) === RUN TestSyncWithUpdateOlder run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dovuxej0zopu'", Local "Local file system at /tmp/rclone1859944754", Modify Window "1ms" 2025/04/15 05:24:42 DEBUG : one: md5 = d64cdbfdde4626b834c998365a890995 OK 2025/04/15 05:24:44 DEBUG : two: md5 = c1d91d8ab06d2dbb45c5a901f83b1a81 OK 2025/04/15 05:24:45 DEBUG : three: md5 = a4b1f15a22d51a4f91a555e16bd43a17 OK 2025/04/15 05:24:47 DEBUG : four: md5 = b5255416bcf35913cb267c190adeddf6 OK 2025/04/15 05:24:47 DEBUG : five: Need to transfer - File not found at Destination 2025/04/15 05:24:47 DEBUG : four: Sizes differ (src 4 vs dst 8) 2025/04/15 05:24:47 DEBUG : one: Destination is newer than source, skipping 2025/04/15 05:24:47 DEBUG : three: Sizes identical 2025/04/15 05:24:47 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dovuxej0zopu': Waiting for checks to finish 2025/04/15 05:24:47 DEBUG : four: Destination mod time is within 1s of source but files differ, transferring 2025/04/15 05:24:47 DEBUG : three: Destination mod time is within 1s of source and files identical, skipping 2025/04/15 05:24:47 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dovuxej0zopu': Waiting for transfers to finish 2025/04/15 05:24:48 DEBUG : four: md5 = d2930a7b2880311da142e890f31abe9b OK 2025/04/15 05:24:48 INFO : four: Copied (replaced existing) 2025/04/15 05:24:48 DEBUG : two: md5 = 6fe71f77e0a35d06c14774a3f20b83f0 OK 2025/04/15 05:24:48 INFO : two: Copied (replaced existing) 2025/04/15 05:24:49 DEBUG : five: md5 = 44d8493cf2fc77e1cb828ab2d8c0523a OK 2025/04/15 05:24:49 INFO : five: Copied (new) 2025/04/15 05:24:49 DEBUG : Waiting for deletions to finish sync_test.go:1449: Skip test with --checksum as no hashes supported --- PASS: TestSyncWithUpdateOlder (10.44s) === 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-dovuxej0zopu'", Local "Local file system at /tmp/rclone1859944754", Modify Window "1ms" sync_test.go:1538: Can track renames: false 2025/04/15 05:24:51 ERROR : Encrypted drive 'TestCryptDrive:rclone-test-dovuxej0zopu': Ignoring --track-renames as the source and destination do not have a common hash 2025/04/15 05:24:52 DEBUG : potato: Need to transfer - File not found at Destination 2025/04/15 05:24:52 DEBUG : yam: Need to transfer - File not found at Destination 2025/04/15 05:24:52 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dovuxej0zopu': Waiting for checks to finish 2025/04/15 05:24:52 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dovuxej0zopu': Waiting for transfers to finish 2025/04/15 05:24:53 DEBUG : potato: md5 = 603c7a554e5b457522aacb9d43e7af49 OK 2025/04/15 05:24:53 INFO : potato: Copied (new) 2025/04/15 05:24:53 DEBUG : yam: md5 = 871dfd37ae17d6d192f2a58f69a416d1 OK 2025/04/15 05:24:53 INFO : yam: Copied (new) 2025/04/15 05:24:53 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dovuxej0zopu'", Local "Local file system at /tmp/rclone1859944754", Modify Window "1ms" 2025/04/15 05:24:53 ERROR : Encrypted drive 'TestCryptDrive:rclone-test-dovuxej0zopu': Ignoring --track-renames as the source and destination do not have a common hash 2025/04/15 05:24:54 DEBUG : potato: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/15 05:24:54 DEBUG : yaml: Need to transfer - File not found at Destination 2025/04/15 05:24:54 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dovuxej0zopu': Waiting for checks to finish 2025/04/15 05:24:54 DEBUG : potato: Unchanged skipping 2025/04/15 05:24:54 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dovuxej0zopu': Waiting for transfers to finish 2025/04/15 05:24:55 DEBUG : yaml: md5 = 7db6ea5fd19e05db660dab6b7ef52022 OK 2025/04/15 05:24:55 INFO : yaml: Copied (new) 2025/04/15 05:24:55 DEBUG : Waiting for deletions to finish 2025/04/15 05:24:55 INFO : yam: Deleted run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dovuxej0zopu'", Local "Local file system at /tmp/rclone1859944754", Modify Window "1ms" --- PASS: TestSyncWithTrackRenames (6.43s) === RUN TestParseRenamesStrategyModtime --- PASS: TestParseRenamesStrategyModtime (0.00s) === RUN TestRenamesStrategyModtime --- PASS: TestRenamesStrategyModtime (0.00s) === RUN TestSyncWithTrackRenamesStrategyModtime run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dovuxej0zopu'", Local "Local file system at /tmp/rclone1859944754", Modify Window "1ms" sync_test.go:1610: Can track renames: true 2025/04/15 05:24:58 INFO : Encrypted drive 'TestCryptDrive:rclone-test-dovuxej0zopu': Making map for --track-renames 2025/04/15 05:24:58 INFO : Encrypted drive 'TestCryptDrive:rclone-test-dovuxej0zopu': Finished making map for --track-renames 2025/04/15 05:24:58 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dovuxej0zopu': Waiting for checks to finish 2025/04/15 05:24:58 DEBUG : potato: Need to transfer - No matching file found at Destination 2025/04/15 05:24:58 DEBUG : yam: Need to transfer - No matching file found at Destination 2025/04/15 05:24:58 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dovuxej0zopu': Waiting for renames to finish 2025/04/15 05:24:58 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dovuxej0zopu': Waiting for transfers to finish 2025/04/15 05:24:59 DEBUG : yam: md5 = b8e357b529b6710f89deb97f9d00c00b OK 2025/04/15 05:24:59 INFO : yam: Copied (new) 2025/04/15 05:24:59 DEBUG : potato: md5 = c56073c7e012a763b04668af8582a212 OK 2025/04/15 05:24:59 INFO : potato: Copied (new) 2025/04/15 05:24:59 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dovuxej0zopu'", Local "Local file system at /tmp/rclone1859944754", Modify Window "1ms" 2025/04/15 05:25:00 DEBUG : potato: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/15 05:25:00 INFO : Encrypted drive 'TestCryptDrive:rclone-test-dovuxej0zopu': Making map for --track-renames 2025/04/15 05:25:00 INFO : Encrypted drive 'TestCryptDrive:rclone-test-dovuxej0zopu': Finished making map for --track-renames 2025/04/15 05:25:00 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dovuxej0zopu': Waiting for checks to finish 2025/04/15 05:25:00 DEBUG : potato: Unchanged skipping 2025/04/15 05:25:00 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dovuxej0zopu': Waiting for renames to finish 2025/04/15 05:25:01 INFO : yam: Moved (server-side) to: yaml 2025/04/15 05:25:01 INFO : yaml: Renamed from "yam" 2025/04/15 05:25:01 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dovuxej0zopu': Waiting for transfers to finish 2025/04/15 05:25:01 DEBUG : Waiting for deletions to finish 2025/04/15 05:25:01 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dovuxej0zopu'", Local "Local file system at /tmp/rclone1859944754", Modify Window "1ms" --- PASS: TestSyncWithTrackRenamesStrategyModtime (5.18s) === RUN TestSyncWithTrackRenamesStrategyLeaf run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dovuxej0zopu'", Local "Local file system at /tmp/rclone1859944754", Modify Window "1ms" sync_test.go:1649: Can track renames: true 2025/04/15 05:25:03 DEBUG : Added delayed dir = "sub", newDst= 2025/04/15 05:25:03 INFO : Encrypted drive 'TestCryptDrive:rclone-test-dovuxej0zopu': Making map for --track-renames 2025/04/15 05:25:03 INFO : Encrypted drive 'TestCryptDrive:rclone-test-dovuxej0zopu': Finished making map for --track-renames 2025/04/15 05:25:03 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dovuxej0zopu': Waiting for checks to finish 2025/04/15 05:25:03 DEBUG : potato: Need to transfer - No matching file found at Destination 2025/04/15 05:25:03 DEBUG : sub/yam: Need to transfer - No matching file found at Destination 2025/04/15 05:25:03 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dovuxej0zopu': Waiting for renames to finish 2025/04/15 05:25:03 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dovuxej0zopu': Waiting for transfers to finish 2025/04/15 05:25:05 DEBUG : potato: md5 = 8ef470836417070ccf7baecc1ddecfc8 OK 2025/04/15 05:25:05 INFO : potato: Copied (new) 2025/04/15 05:25:06 DEBUG : sub/yam: md5 = 513789dd9a16b040b016eb89c5792b9e OK 2025/04/15 05:25:06 INFO : sub/yam: Copied (new) 2025/04/15 05:25:06 DEBUG : Waiting for deletions to finish 2025/04/15 05:25:06 INFO : sub: Set directory modification time (using DirSetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dovuxej0zopu'", Local "Local file system at /tmp/rclone1859944754", Modify Window "1ms" 2025/04/15 05:25:07 DEBUG : potato: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/15 05:25:07 DEBUG : potato: Unchanged skipping 2025/04/15 05:25:07 INFO : sub: Set directory modification time (using SetModTime) 2025/04/15 05:25:07 DEBUG : Added delayed dir = "sub", newDst=sub 2025/04/15 05:25:07 INFO : Encrypted drive 'TestCryptDrive:rclone-test-dovuxej0zopu': Making map for --track-renames 2025/04/15 05:25:07 INFO : Encrypted drive 'TestCryptDrive:rclone-test-dovuxej0zopu': Finished making map for --track-renames 2025/04/15 05:25:07 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dovuxej0zopu': Waiting for checks to finish 2025/04/15 05:25:07 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dovuxej0zopu': Waiting for renames to finish 2025/04/15 05:25:08 INFO : sub/yam: Moved (server-side) to: yam 2025/04/15 05:25:08 INFO : yam: Renamed from "sub/yam" 2025/04/15 05:25:08 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dovuxej0zopu': Waiting for transfers to finish 2025/04/15 05:25:08 DEBUG : Waiting for deletions to finish 2025/04/15 05:25:08 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dovuxej0zopu'", Local "Local file system at /tmp/rclone1859944754", Modify Window "1ms" --- PASS: TestSyncWithTrackRenamesStrategyLeaf (8.82s) === RUN TestServerSideMoveLocal run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dovuxej0zopu'", Local "Local file system at /tmp/rclone1859944754", Modify Window "1ms" 2025/04/15 05:25:12 DEBUG : Creating backend with remote "/tmp/rclone1859944754/dir1" 2025/04/15 05:25:12 DEBUG : Creating backend with remote "/tmp/rclone1859944754/dir2" 2025/04/15 05:25:12 DEBUG : Local file system at /tmp/rclone1859944754/dir2: Using server-side directory move 2025/04/15 05:25:12 INFO : Local file system at /tmp/rclone1859944754/dir2: Server side directory move failed - fallback to file moves: can't copy directory - destination already exists 2025/04/15 05:25:12 DEBUG : file1.txt: Need to transfer - File not found at Destination 2025/04/15 05:25:12 INFO : file1.txt: Moved (server-side) 2025/04/15 05:25:12 DEBUG : Local file system at /tmp/rclone1859944754/dir2: Waiting for checks to finish 2025/04/15 05:25:12 DEBUG : Local file system at /tmp/rclone1859944754/dir2: Waiting for transfers to finish --- PASS: TestServerSideMoveLocal (0.41s) === RUN TestMoveWithDeleteEmptySrcDirs run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dovuxej0zopu'", Local "Local file system at /tmp/rclone1859944754", Modify Window "1ms" 2025/04/15 05:25:13 DEBUG : Added delayed dir = "nested", newDst= 2025/04/15 05:25:13 DEBUG : Added delayed dir = "sub dir", newDst= 2025/04/15 05:25:13 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2025/04/15 05:25:13 DEBUG : Added delayed dir = "nested/sub dir", newDst= 2025/04/15 05:25:13 DEBUG : nested/sub dir/file: Need to transfer - File not found at Destination 2025/04/15 05:25:13 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dovuxej0zopu': Waiting for checks to finish 2025/04/15 05:25:13 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dovuxej0zopu': Waiting for transfers to finish 2025/04/15 05:25:15 DEBUG : sub dir/hello world: md5 = 151a1e5286a73d4731acf950497c26ee OK 2025/04/15 05:25:15 INFO : sub dir/hello world: Copied (new) 2025/04/15 05:25:15 INFO : sub dir/hello world: Deleted 2025/04/15 05:25:16 DEBUG : nested/sub dir/file: md5 = 269dfe534b611a237fb880c52d555a6c OK 2025/04/15 05:25:16 INFO : nested/sub dir/file: Copied (new) 2025/04/15 05:25:16 INFO : nested/sub dir/file: Deleted 2025/04/15 05:25:17 INFO : nested/sub dir: Set directory modification time (using DirSetModTime) 2025/04/15 05:25:17 INFO : sub dir: Set directory modification time (using DirSetModTime) 2025/04/15 05:25:17 INFO : nested: Set directory modification time (using DirSetModTime) 2025/04/15 05:25:17 INFO : sub dir: Removing directory 2025/04/15 05:25:17 INFO : nested/sub dir: Removing directory 2025/04/15 05:25:17 INFO : nested: Removing directory 2025/04/15 05:25:17 DEBUG : Local file system at /tmp/rclone1859944754: deleted 3 directories run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dovuxej0zopu'", Local "Local file system at /tmp/rclone1859944754", Modify Window "1ms" 2025/04/15 05:25:20 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" 2025/04/15 05:25:21 DEBUG : 37qp6d1gohacv723ij3brofbu8/14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "ftp4kuv8se7tqduu6pmmcvjsmk" 2025/04/15 05:25:22 DEBUG : 37qp6d1gohacv723ij3brofbu8: Rmdir: contains trashed file: "14begaa36ih249fgrnfk6nulg0" --- PASS: TestMoveWithDeleteEmptySrcDirs (10.31s) === RUN TestMoveWithoutDeleteEmptySrcDirs run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dovuxej0zopu'", Local "Local file system at /tmp/rclone1859944754", Modify Window "1ms" 2025/04/15 05:25:23 DEBUG : Added delayed dir = "nested", newDst= 2025/04/15 05:25:23 DEBUG : Added delayed dir = "sub dir", newDst= 2025/04/15 05:25:23 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2025/04/15 05:25:23 DEBUG : Added delayed dir = "nested/sub dir", newDst= 2025/04/15 05:25:23 DEBUG : nested/sub dir/file: Need to transfer - File not found at Destination 2025/04/15 05:25:23 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dovuxej0zopu': Waiting for checks to finish 2025/04/15 05:25:23 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dovuxej0zopu': Waiting for transfers to finish 2025/04/15 05:25:25 DEBUG : sub dir/hello world: md5 = 81ec8f97d32d3aef50d8ad9afa93740c OK 2025/04/15 05:25:25 INFO : sub dir/hello world: Copied (new) 2025/04/15 05:25:25 INFO : sub dir/hello world: Deleted 2025/04/15 05:25:27 DEBUG : nested/sub dir/file: md5 = 5a047ae4accdb769169f4dfd62e21289 OK 2025/04/15 05:25:27 INFO : nested/sub dir/file: Copied (new) 2025/04/15 05:25:27 INFO : nested/sub dir/file: Deleted 2025/04/15 05:25:27 INFO : nested/sub dir: Set directory modification time (using DirSetModTime) 2025/04/15 05:25:28 INFO : nested: Set directory modification time (using DirSetModTime) 2025/04/15 05:25:28 INFO : sub dir: Set directory modification time (using DirSetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dovuxej0zopu'", Local "Local file system at /tmp/rclone1859944754", Modify Window "1ms" 2025/04/15 05:25:30 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" 2025/04/15 05:25:31 DEBUG : 37qp6d1gohacv723ij3brofbu8/14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "ftp4kuv8se7tqduu6pmmcvjsmk" 2025/04/15 05:25:32 DEBUG : 37qp6d1gohacv723ij3brofbu8: Rmdir: contains trashed file: "14begaa36ih249fgrnfk6nulg0" --- PASS: TestMoveWithoutDeleteEmptySrcDirs (10.29s) === RUN TestMoveWithIgnoreExisting run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dovuxej0zopu'", Local "Local file system at /tmp/rclone1859944754", Modify Window "1ms" 2025/04/15 05:25:33 DEBUG : existing: Need to transfer - File not found at Destination 2025/04/15 05:25:33 DEBUG : existing-b: Need to transfer - File not found at Destination 2025/04/15 05:25:33 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dovuxej0zopu': Waiting for checks to finish 2025/04/15 05:25:33 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dovuxej0zopu': Waiting for transfers to finish 2025/04/15 05:25:34 DEBUG : existing-b: md5 = 440831043b95dc0b2dd070bdb32edc19 OK 2025/04/15 05:25:34 INFO : existing-b: Copied (new) 2025/04/15 05:25:34 INFO : existing-b: Deleted 2025/04/15 05:25:35 DEBUG : existing: md5 = 64f051bf65919a4b8c64d0fd386d5d8c OK 2025/04/15 05:25:35 INFO : existing: Copied (new) 2025/04/15 05:25:35 INFO : existing: Deleted 2025/04/15 05:25:35 DEBUG : existing: Destination exists, skipping 2025/04/15 05:25:35 DEBUG : existing: Not removing source file as destination file exists and --ignore-existing is set 2025/04/15 05:25:35 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dovuxej0zopu': Waiting for checks to finish 2025/04/15 05:25:35 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dovuxej0zopu': Waiting for transfers to finish 2025/04/15 05:25:35 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dovuxej0zopu'", Local "Local file system at /tmp/rclone1859944754", Modify Window "1ms" --- PASS: TestMoveWithIgnoreExisting (4.47s) === RUN TestServerSideMove run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dovuxej0zopu'", Local "Local file system at /tmp/rclone1859944754", Modify Window "1ms" 2025/04/15 05:25:37 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-mivomud6boyu" 2025/04/15 05:25:37 DEBUG : Creating backend with remote "TestDrive:crypt/pllgphfs4vhhbp9971oruckof2vik0o65c8h3dvi0gkhbgotjdsg" 2025/04/15 05:25:40 DEBUG : potato2: md5 = 2fb4e4fb6f545f75723f2e8bc074ac9d OK 2025/04/15 05:25:42 DEBUG : empty space: md5 = d8c2ad0874853b1c033e7a42fa900afb OK 2025/04/15 05:25:43 DEBUG : potato3: md5 = 8271dc87fdcd69d5aaa339bb7d6bd130 OK sync_test.go:1705: Server side move (if possible) Encrypted drive 'TestCryptDrive:rclone-test-dovuxej0zopu' -> Encrypted drive 'TestCryptDrive:rclone-test-mivomud6boyu' 2025/04/15 05:25:46 DEBUG : empty space: md5 = 23e1f3b4c7313c709f12af5dd29780b4 OK 2025/04/15 05:25:47 DEBUG : potato3: md5 = 0f1fa360dc0b2d9971730cc24cdb7074 OK 2025/04/15 05:25:47 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mivomud6boyu': Using server-side directory move 2025/04/15 05:25:47 INFO : Encrypted drive 'TestCryptDrive:rclone-test-mivomud6boyu': Server side directory move failed - fallback to file moves: can't copy directory - destination already exists 2025/04/15 05:25:48 DEBUG : potato2: Need to transfer - File not found at Destination 2025/04/15 05:25:48 DEBUG : empty space: Size and modification time the same (differ by 0s, within tolerance 1ms) 2025/04/15 05:25:48 DEBUG : empty space: Unchanged skipping 2025/04/15 05:25:48 DEBUG : potato3: Sizes differ (src 68 vs dst 60) 2025/04/15 05:25:48 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mivomud6boyu': Waiting for checks to finish 2025/04/15 05:25:48 INFO : potato3: Deleted 2025/04/15 05:25:48 INFO : empty space: Deleted 2025/04/15 05:25:48 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mivomud6boyu': Waiting for transfers to finish 2025/04/15 05:25:48 INFO : potato2: Moved (server-side) 2025/04/15 05:25:49 INFO : potato3: Moved (server-side) 2025/04/15 05:25:49 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-yuhateb6tiha" 2025/04/15 05:25:49 DEBUG : Creating backend with remote "TestDrive:crypt/j4mk0ec1qunnf1leb3bl9k27ikrg05trurr0kj9l57ujqrk34bu0" 2025/04/15 05:25:50 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yuhateb6tiha': Using server-side directory move 2025/04/15 05:25:51 INFO : Encrypted drive 'TestCryptDrive:rclone-test-yuhateb6tiha': Server side directory move succeeded 2025/04/15 05:25:52 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yuhateb6tiha': Purge remote 2025/04/15 05:25:53 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mivomud6boyu': Purge remote 2025/04/15 05:25:53 NOTICE: purge failed: directory not found --- PASS: TestServerSideMove (15.95s) === RUN TestServerSideMoveWithFilter run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dovuxej0zopu'", Local "Local file system at /tmp/rclone1859944754", Modify Window "1ms" 2025/04/15 05:25:53 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-xupafaw1boxi" 2025/04/15 05:25:53 DEBUG : Creating backend with remote "TestDrive:crypt/n83rcjhs9g4n4t6ojed1ftd14rhljnue8irc458e0qemb6loa73g" 2025/04/15 05:25:56 DEBUG : potato2: md5 = ee3c8cc53ac6eca4ed37bb6fc3b2ee50 OK 2025/04/15 05:25:57 DEBUG : empty space: md5 = 2bffbc7c2f7c5e699a9a2f8aba6f07fe OK 2025/04/15 05:25:59 DEBUG : potato3: md5 = 06f9a6d2550ee8d14c6fb08360611d41 OK sync_test.go:1705: Server side move (if possible) Encrypted drive 'TestCryptDrive:rclone-test-dovuxej0zopu' -> Encrypted drive 'TestCryptDrive:rclone-test-xupafaw1boxi' 2025/04/15 05:26:01 DEBUG : empty space: md5 = 82bbc4c62e37654d0fa3acd031918346 OK 2025/04/15 05:26:02 DEBUG : potato3: md5 = 5ae61c09021a59322cfce92328ee5f1f OK 2025/04/15 05:26:03 DEBUG : empty space: Excluded (Size Filter) 2025/04/15 05:26:03 DEBUG : empty space: Excluded (Size Filter) 2025/04/15 05:26:03 DEBUG : potato2: Need to transfer - File not found at Destination 2025/04/15 05:26:03 DEBUG : potato3: Sizes differ (src 68 vs dst 60) 2025/04/15 05:26:03 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-xupafaw1boxi': Waiting for checks to finish 2025/04/15 05:26:03 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-xupafaw1boxi': Waiting for transfers to finish 2025/04/15 05:26:03 INFO : potato3: Deleted 2025/04/15 05:26:04 INFO : potato2: Moved (server-side) 2025/04/15 05:26:04 INFO : potato3: Moved (server-side) 2025/04/15 05:26:04 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-quruviq4nika" 2025/04/15 05:26:05 DEBUG : Creating backend with remote "TestDrive:crypt/pf3dle2f1m2kbufa6cngr9a05kvl76a6kg4a3cnbciq7v0mrajvg" 2025/04/15 05:26:06 DEBUG : empty space: Excluded (Size Filter) 2025/04/15 05:26:06 DEBUG : potato2: Need to transfer - File not found at Destination 2025/04/15 05:26:06 DEBUG : potato3: Need to transfer - File not found at Destination 2025/04/15 05:26:06 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-quruviq4nika': Waiting for checks to finish 2025/04/15 05:26:06 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-quruviq4nika': Waiting for transfers to finish 2025/04/15 05:26:07 INFO : potato2: Moved (server-side) 2025/04/15 05:26:07 INFO : potato3: Moved (server-side) 2025/04/15 05:26:08 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-quruviq4nika': Purge remote 2025/04/15 05:26:08 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-xupafaw1boxi': Purge remote --- PASS: TestServerSideMoveWithFilter (16.16s) === RUN TestServerSideMoveDeleteEmptySourceDirs run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dovuxej0zopu'", Local "Local file system at /tmp/rclone1859944754", Modify Window "1ms" 2025/04/15 05:26:09 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-tayahov7hepa" 2025/04/15 05:26:10 DEBUG : Creating backend with remote "TestDrive:crypt/k9ja8le80vaob0qiu0emv9vsun3tit6s0olbt5u8mdo3eor9cveg" 2025/04/15 05:26:12 DEBUG : potato2: md5 = 5b6d178c54756f96f263bed836431989 OK 2025/04/15 05:26:13 DEBUG : empty space: md5 = dc6db3f24c7fa7f2fea89e4221a98775 OK 2025/04/15 05:26:15 DEBUG : potato3: md5 = 216ef044b588783897db18d7b01b4849 OK 2025/04/15 05:26:15 INFO : tomatoDir: Making directory sync_test.go:1705: Server side move (if possible) Encrypted drive 'TestCryptDrive:rclone-test-dovuxej0zopu' -> Encrypted drive 'TestCryptDrive:rclone-test-tayahov7hepa' 2025/04/15 05:26:18 DEBUG : empty space: md5 = 13df979a9d434f44d21351d748813978 OK 2025/04/15 05:26:19 DEBUG : potato3: md5 = 81b9be4a194e6d72416f6e5d504dc5bb OK 2025/04/15 05:26:20 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tayahov7hepa': Using server-side directory move 2025/04/15 05:26:20 INFO : Encrypted drive 'TestCryptDrive:rclone-test-tayahov7hepa': Server side directory move failed - fallback to file moves: can't copy directory - destination already exists 2025/04/15 05:26:20 DEBUG : potato2: Need to transfer - File not found at Destination 2025/04/15 05:26:20 DEBUG : Added delayed dir = "tomatoDir", newDst= 2025/04/15 05:26:20 DEBUG : empty space: Size and modification time the same (differ by 0s, within tolerance 1ms) 2025/04/15 05:26:20 DEBUG : empty space: Unchanged skipping 2025/04/15 05:26:20 DEBUG : potato3: Sizes differ (src 68 vs dst 60) 2025/04/15 05:26:20 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tayahov7hepa': Waiting for checks to finish 2025/04/15 05:26:21 INFO : empty space: Deleted 2025/04/15 05:26:21 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tayahov7hepa': Waiting for transfers to finish 2025/04/15 05:26:21 INFO : potato3: Deleted 2025/04/15 05:26:21 INFO : potato2: Moved (server-side) 2025/04/15 05:26:21 INFO : potato3: Moved (server-side) 2025/04/15 05:26:21 INFO : tomatoDir: Removing directory 2025/04/15 05:26:22 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dovuxej0zopu': deleted 1 directories 2025/04/15 05:26:22 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-besixah2xuye" 2025/04/15 05:26:22 DEBUG : Creating backend with remote "TestDrive:crypt/v4rmqe8nk3a1ogr65m9bppvofqtgndedgqm58t9kcfg4jtd3ij9g" 2025/04/15 05:26:23 INFO : tomatoDir: Making directory 2025/04/15 05:26:24 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-besixah2xuye': Using server-side directory move 2025/04/15 05:26:25 INFO : Encrypted drive 'TestCryptDrive:rclone-test-besixah2xuye': Server side directory move succeeded 2025/04/15 05:26:26 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-besixah2xuye': Purge remote 2025/04/15 05:26:27 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tayahov7hepa': Purge remote 2025/04/15 05:26:27 NOTICE: purge failed: directory not found --- PASS: TestServerSideMoveDeleteEmptySourceDirs (18.03s) === RUN TestServerSideMoveOverlap run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dovuxej0zopu'", Local "Local file system at /tmp/rclone1859944754", Modify Window "1ms" sync_test.go:1910: Skipping test as remote supports DirMove --- SKIP: TestServerSideMoveOverlap (0.44s) === RUN TestSyncOverlap run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dovuxej0zopu'", Local "Local file system at /tmp/rclone1859944754", Modify Window "1ms" 2025/04/15 05:26:28 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-dovuxej0zopu/rclone-sync-test" 2025/04/15 05:26:28 DEBUG : Creating backend with remote "TestDrive:crypt/smlh8e653n38ba8jg0ed6f8tncp8o8vm9ic9r24gp4sdufv0g7r0/i7355aa0sb89uagn75vfjqr6s3e3e1h2et8in57abn1fe8qfego0" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dovuxej0zopu'", Local "Local file system at /tmp/rclone1859944754", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dovuxej0zopu'", Local "Local file system at /tmp/rclone1859944754", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dovuxej0zopu'", Local "Local file system at /tmp/rclone1859944754", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dovuxej0zopu'", Local "Local file system at /tmp/rclone1859944754", Modify Window "1ms" --- PASS: TestSyncOverlap (3.60s) === RUN TestSyncOverlapWithFilter run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dovuxej0zopu'", Local "Local file system at /tmp/rclone1859944754", Modify Window "1ms" 2025/04/15 05:26:32 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-dovuxej0zopu/rclone-sync-test" 2025/04/15 05:26:32 DEBUG : Creating backend with remote "TestDrive:crypt/smlh8e653n38ba8jg0ed6f8tncp8o8vm9ic9r24gp4sdufv0g7r0/i7355aa0sb89uagn75vfjqr6s3e3e1h2et8in57abn1fe8qfego0" 2025/04/15 05:26:34 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-dovuxej0zopu/rclone-sync-test-include/layer2" 2025/04/15 05:26:34 DEBUG : Creating backend with remote "TestDrive:crypt/smlh8e653n38ba8jg0ed6f8tncp8o8vm9ic9r24gp4sdufv0g7r0/khf2vlblvnbf9ftevqm0htmss73hj1j5a7q328e4ohrgs7e2loe0/n01jpl9202nn9ec1rb75h0f1c4" 2025/04/15 05:26:37 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-dovuxej0zopu/rclone-sync-test-ignore-file" 2025/04/15 05:26:37 DEBUG : Creating backend with remote "TestDrive:crypt/smlh8e653n38ba8jg0ed6f8tncp8o8vm9ic9r24gp4sdufv0g7r0/kmf11jujl9uha3tjganvgpkn45bu778hb5vb5riug1c26b38k7sg" 2025/04/15 05:26:41 DEBUG : rclone-sync-test-ignore-file/.ignore: md5 = 8db8220a27bbc4097c4ee84c616950ef OK 2025/04/15 05:26:43 DEBUG : Added delayed dir = "rclone-sync-test-include", newDst= 2025/04/15 05:26:43 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dovuxej0zopu/rclone-sync-test': Waiting for checks to finish 2025/04/15 05:26:43 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dovuxej0zopu/rclone-sync-test': Waiting for transfers to finish 2025/04/15 05:26:43 DEBUG : Waiting for deletions to finish 2025/04/15 05:26:43 INFO : There was nothing to transfer 2025/04/15 05:26:45 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dovuxej0zopu': Waiting for checks to finish 2025/04/15 05:26:45 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dovuxej0zopu': Waiting for transfers to finish 2025/04/15 05:26:45 DEBUG : Waiting for deletions to finish 2025/04/15 05:26:45 INFO : rclone-sync-test-include: Removing directory 2025/04/15 05:26:45 DEBUG : khf2vlblvnbf9ftevqm0htmss73hj1j5a7q328e4ohrgs7e2loe0: Rmdir: contains file: "n01jpl9202nn9ec1rb75h0f1c4" 2025/04/15 05:26:45 DEBUG : rclone-sync-test-include: Failed to Rmdir: directory not empty 2025/04/15 05:26:45 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dovuxej0zopu': failed to delete 1 directories 2025/04/15 05:26:45 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dovuxej0zopu'", Local "Local file system at /tmp/rclone1859944754", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dovuxej0zopu'", Local "Local file system at /tmp/rclone1859944754", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dovuxej0zopu'", Local "Local file system at /tmp/rclone1859944754", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dovuxej0zopu'", Local "Local file system at /tmp/rclone1859944754", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dovuxej0zopu'", Local "Local file system at /tmp/rclone1859944754", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dovuxej0zopu'", Local "Local file system at /tmp/rclone1859944754", Modify Window "1ms" 2025/04/15 05:26:46 DEBUG : Added delayed dir = "rclone-sync-test-include", newDst= 2025/04/15 05:26:46 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dovuxej0zopu/rclone-sync-test-include/layer2': Waiting for checks to finish 2025/04/15 05:26:46 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dovuxej0zopu/rclone-sync-test-include/layer2': Waiting for transfers to finish 2025/04/15 05:26:46 DEBUG : Waiting for deletions to finish 2025/04/15 05:26:46 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dovuxej0zopu'", Local "Local file system at /tmp/rclone1859944754", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dovuxej0zopu'", Local "Local file system at /tmp/rclone1859944754", Modify Window "1ms" 2025/04/15 05:26:48 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dovuxej0zopu': Waiting for checks to finish 2025/04/15 05:26:48 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dovuxej0zopu': Waiting for transfers to finish 2025/04/15 05:26:48 DEBUG : Waiting for deletions to finish 2025/04/15 05:26:48 INFO : rclone-sync-test-include: Removing directory 2025/04/15 05:26:49 DEBUG : khf2vlblvnbf9ftevqm0htmss73hj1j5a7q328e4ohrgs7e2loe0: Rmdir: contains file: "n01jpl9202nn9ec1rb75h0f1c4" 2025/04/15 05:26:49 DEBUG : rclone-sync-test-include: Failed to Rmdir: directory not empty 2025/04/15 05:26:49 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dovuxej0zopu': failed to delete 1 directories 2025/04/15 05:26:49 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dovuxej0zopu'", Local "Local file system at /tmp/rclone1859944754", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dovuxej0zopu'", Local "Local file system at /tmp/rclone1859944754", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dovuxej0zopu'", Local "Local file system at /tmp/rclone1859944754", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dovuxej0zopu'", Local "Local file system at /tmp/rclone1859944754", Modify Window "1ms" 2025/04/15 05:26:50 DEBUG : Added delayed dir = "rclone-sync-test-include", newDst= 2025/04/15 05:26:50 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dovuxej0zopu/rclone-sync-test-ignore-file': Waiting for checks to finish 2025/04/15 05:26:50 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dovuxej0zopu/rclone-sync-test-ignore-file': Waiting for transfers to finish 2025/04/15 05:26:50 DEBUG : Waiting for deletions to finish 2025/04/15 05:26:50 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dovuxej0zopu'", Local "Local file system at /tmp/rclone1859944754", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dovuxej0zopu'", Local "Local file system at /tmp/rclone1859944754", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dovuxej0zopu'", Local "Local file system at /tmp/rclone1859944754", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dovuxej0zopu'", Local "Local file system at /tmp/rclone1859944754", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dovuxej0zopu'", Local "Local file system at /tmp/rclone1859944754", Modify Window "1ms" 2025/04/15 05:26:52 DEBUG : khf2vlblvnbf9ftevqm0htmss73hj1j5a7q328e4ohrgs7e2loe0: Rmdir: contains trashed file: "n01jpl9202nn9ec1rb75h0f1c4" 2025/04/15 05:26:53 DEBUG : kmf11jujl9uha3tjganvgpkn45bu778hb5vb5riug1c26b38k7sg: Rmdir: contains trashed file: "i0t74httmdlljg425j6tg570d8" --- PASS: TestSyncOverlapWithFilter (31.07s) === RUN TestSyncCompareDest run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dovuxej0zopu'", Local "Local file system at /tmp/rclone1859944754", Modify Window "1ms" 2025/04/15 05:27:03 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-dovuxej0zopu/dst" 2025/04/15 05:27:03 DEBUG : Creating backend with remote "TestDrive:crypt/smlh8e653n38ba8jg0ed6f8tncp8o8vm9ic9r24gp4sdufv0g7r0/31u3jie661vd5p8j7rtc3hgbh0" 2025/04/15 05:27:04 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-dovuxej0zopu/CompareDest" 2025/04/15 05:27:04 DEBUG : Creating backend with remote "TestDrive:crypt/smlh8e653n38ba8jg0ed6f8tncp8o8vm9ic9r24gp4sdufv0g7r0/gveqi14airsml4bgu7krj116o8" 2025/04/15 05:27:06 DEBUG : one: Need to transfer - File not found at Destination 2025/04/15 05:27:06 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dovuxej0zopu/dst': Waiting for checks to finish 2025/04/15 05:27:06 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dovuxej0zopu/dst': Waiting for transfers to finish 2025/04/15 05:27:08 DEBUG : one: md5 = 7a4d7e29dacdd11a5492106cfb434b68 OK 2025/04/15 05:27:08 INFO : one: Copied (new) 2025/04/15 05:27:08 DEBUG : Waiting for deletions to finish 2025/04/15 05:27:09 DEBUG : one: Sizes differ (src 5 vs dst 3) 2025/04/15 05:27:09 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dovuxej0zopu/dst': Waiting for checks to finish 2025/04/15 05:27:10 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dovuxej0zopu/dst': Waiting for transfers to finish 2025/04/15 05:27:11 DEBUG : one: md5 = 7d35c631683df5c01c9667ff58eec4c4 OK 2025/04/15 05:27:11 INFO : one: Copied (replaced existing) 2025/04/15 05:27:11 DEBUG : Waiting for deletions to finish 2025/04/15 05:27:13 DEBUG : dst/one: md5 = aa2eb44a1c3e4690e80a0999d21f11b6 OK 2025/04/15 05:27:15 DEBUG : CompareDest/one: md5 = dfae66f809f73e026250fc792e8fb4c1 OK 2025/04/15 05:27:15 DEBUG : one: Sizes differ (src 5 vs dst 3) 2025/04/15 05:27:15 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dovuxej0zopu/dst': Waiting for checks to finish 2025/04/15 05:27:16 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/04/15 05:27:16 DEBUG : one: Destination found in --compare-dest, skipping 2025/04/15 05:27:16 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dovuxej0zopu/dst': Waiting for transfers to finish 2025/04/15 05:27:16 DEBUG : Waiting for deletions to finish 2025/04/15 05:27:16 INFO : There was nothing to transfer 2025/04/15 05:27:18 DEBUG : CompareDest/two: md5 = 1efdd83c9a54877636308f5c49593c5e OK 2025/04/15 05:27:18 DEBUG : one: Sizes differ (src 5 vs dst 3) 2025/04/15 05:27:19 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/04/15 05:27:19 DEBUG : one: Destination found in --compare-dest, skipping 2025/04/15 05:27:19 DEBUG : two: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/04/15 05:27:19 DEBUG : two: Destination found in --compare-dest, skipping 2025/04/15 05:27:19 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dovuxej0zopu/dst': Waiting for checks to finish 2025/04/15 05:27:19 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dovuxej0zopu/dst': Waiting for transfers to finish 2025/04/15 05:27:19 DEBUG : Waiting for deletions to finish 2025/04/15 05:27:19 INFO : There was nothing to transfer 2025/04/15 05:27:19 DEBUG : one: Sizes differ (src 5 vs dst 3) 2025/04/15 05:27:19 DEBUG : two: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/04/15 05:27:19 DEBUG : two: Destination found in --compare-dest, skipping 2025/04/15 05:27:19 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dovuxej0zopu/dst': Waiting for checks to finish 2025/04/15 05:27:19 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/04/15 05:27:19 DEBUG : one: Destination found in --compare-dest, skipping 2025/04/15 05:27:19 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dovuxej0zopu/dst': Waiting for transfers to finish 2025/04/15 05:27:19 DEBUG : Waiting for deletions to finish 2025/04/15 05:27:19 INFO : There was nothing to transfer sync_test.go:2175: No hash on uploaded file so skipping compare timestamp test 2025/04/15 05:27:21 DEBUG : one: Sizes differ (src 5 vs dst 3) 2025/04/15 05:27:21 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/04/15 05:27:21 DEBUG : one: Destination found in --compare-dest, skipping 2025/04/15 05:27:21 DEBUG : two: Sizes differ (src 5 vs dst 3) 2025/04/15 05:27:21 DEBUG : two: Need to transfer - File not found at Destination 2025/04/15 05:27:21 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dovuxej0zopu/dst': Waiting for checks to finish 2025/04/15 05:27:21 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dovuxej0zopu/dst': Waiting for transfers to finish 2025/04/15 05:27:22 DEBUG : two: md5 = 0d6389197dbc7f29e63dd9e5e1e0940b OK 2025/04/15 05:27:22 INFO : two: Copied (new) 2025/04/15 05:27:22 DEBUG : Waiting for deletions to finish 2025/04/15 05:27:25 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k" 2025/04/15 05:27:25 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" 2025/04/15 05:27:26 DEBUG : gveqi14airsml4bgu7krj116o8: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k" 2025/04/15 05:27:26 DEBUG : gveqi14airsml4bgu7krj116o8: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" --- PASS: TestSyncCompareDest (23.95s) === RUN TestSyncMultipleCompareDest run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dovuxej0zopu'", Local "Local file system at /tmp/rclone1859944754", Modify Window "1ms" 2025/04/15 05:27:29 DEBUG : pre-dest1/1: md5 = eaac93956a0f7099c21e5734983504bf OK 2025/04/15 05:27:31 DEBUG : pre-dest2/2: md5 = 84b71e58e0f3d4b6ffeedbe219dbe49c OK 2025/04/15 05:27:31 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-dovuxej0zopu/dest" 2025/04/15 05:27:31 DEBUG : Creating backend with remote "TestDrive:crypt/smlh8e653n38ba8jg0ed6f8tncp8o8vm9ic9r24gp4sdufv0g7r0/rg03c1jvnehrrc617i0lnqjddc" 2025/04/15 05:27:33 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-dovuxej0zopu/pre-dest1" 2025/04/15 05:27:33 DEBUG : Creating backend with remote "TestDrive:crypt/smlh8e653n38ba8jg0ed6f8tncp8o8vm9ic9r24gp4sdufv0g7r0/bbnblvh6k061ssopqrp18kd7gc" 2025/04/15 05:27:33 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-dovuxej0zopu/pre-dest2" 2025/04/15 05:27:34 DEBUG : Creating backend with remote "TestDrive:crypt/smlh8e653n38ba8jg0ed6f8tncp8o8vm9ic9r24gp4sdufv0g7r0/dgicm1h6b5ejvlltm8eeif0bnk" 2025/04/15 05:27:35 DEBUG : 1: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/15 05:27:35 DEBUG : 1: Destination found in --compare-dest, skipping 2025/04/15 05:27:35 DEBUG : 2: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/15 05:27:35 DEBUG : 2: Destination found in --compare-dest, skipping 2025/04/15 05:27:36 DEBUG : 3: Need to transfer - File not found at Destination 2025/04/15 05:27:36 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dovuxej0zopu/dest': Waiting for checks to finish 2025/04/15 05:27:36 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dovuxej0zopu/dest': Waiting for transfers to finish 2025/04/15 05:27:38 DEBUG : 3: md5 = fef9e12a49a88b7702e3d649bf0e9321 OK 2025/04/15 05:27:38 INFO : 3: Copied (new) 2025/04/15 05:27:38 DEBUG : Waiting for deletions to finish 2025/04/15 05:27:40 DEBUG : dgicm1h6b5ejvlltm8eeif0bnk: Rmdir: contains trashed file: "1ghu8geql9vrl726n32nrf65bc" 2025/04/15 05:27:41 DEBUG : bbnblvh6k061ssopqrp18kd7gc: Rmdir: contains trashed file: "skbfko3oil7es0lj68ob574sro" 2025/04/15 05:27:42 DEBUG : rg03c1jvnehrrc617i0lnqjddc: Rmdir: contains trashed file: "g072p7hmjchlnj0gibe64c1epg" --- PASS: TestSyncMultipleCompareDest (15.91s) === RUN TestSyncCopyDest run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dovuxej0zopu'", Local "Local file system at /tmp/rclone1859944754", Modify Window "1ms" 2025/04/15 05:27:42 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-dovuxej0zopu/dst" 2025/04/15 05:27:43 DEBUG : Creating backend with remote "TestDrive:crypt/smlh8e653n38ba8jg0ed6f8tncp8o8vm9ic9r24gp4sdufv0g7r0/31u3jie661vd5p8j7rtc3hgbh0" 2025/04/15 05:27:44 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-dovuxej0zopu/CopyDest" 2025/04/15 05:27:44 DEBUG : Creating backend with remote "TestDrive:crypt/smlh8e653n38ba8jg0ed6f8tncp8o8vm9ic9r24gp4sdufv0g7r0/d09o6po3f7bm6ce32vdgs8h9ls" 2025/04/15 05:27:46 DEBUG : one: Need to transfer - File not found at Destination 2025/04/15 05:27:46 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dovuxej0zopu/dst': Waiting for checks to finish 2025/04/15 05:27:46 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dovuxej0zopu/dst': Waiting for transfers to finish 2025/04/15 05:27:48 DEBUG : one: md5 = 9a4ff1c73a24521525f1ae5583a296b0 OK 2025/04/15 05:27:48 INFO : one: Copied (new) 2025/04/15 05:27:48 DEBUG : Waiting for deletions to finish 2025/04/15 05:27:49 DEBUG : one: Sizes differ (src 5 vs dst 3) 2025/04/15 05:27:49 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dovuxej0zopu/dst': Waiting for checks to finish 2025/04/15 05:27:50 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dovuxej0zopu/dst': Waiting for transfers to finish 2025/04/15 05:27:51 DEBUG : one: md5 = 71e4bc68e8666035aa63646444dd9640 OK 2025/04/15 05:27:51 INFO : one: Copied (replaced existing) 2025/04/15 05:27:51 DEBUG : Waiting for deletions to finish 2025/04/15 05:27:53 DEBUG : dst/one: md5 = c364d431de91ab49125f9474730dfaa3 OK 2025/04/15 05:27:55 DEBUG : CopyDest/one: md5 = 5dfd96ea746e34d28efcf57540d17d78 OK 2025/04/15 05:27:55 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-dovuxej0zopu/BackupDir" 2025/04/15 05:27:55 DEBUG : Creating backend with remote "TestDrive:crypt/smlh8e653n38ba8jg0ed6f8tncp8o8vm9ic9r24gp4sdufv0g7r0/s6dbk3lfi7c9kfvo6j7bla9m0g" 2025/04/15 05:27:57 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dovuxej0zopu/dst': Waiting for checks to finish 2025/04/15 05:27:57 DEBUG : one: Sizes differ (src 5 vs dst 3) 2025/04/15 05:27:57 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/04/15 05:27:57 DEBUG : one: Sizes differ (src 5 vs dst 3) 2025/04/15 05:27:59 INFO : one: Moved (server-side) 2025/04/15 05:28:00 INFO : one: Copied (server-side copy) 2025/04/15 05:28:00 DEBUG : one: Destination found in --copy-dest, using server-side copy 2025/04/15 05:28:00 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dovuxej0zopu/dst': Waiting for transfers to finish 2025/04/15 05:28:00 DEBUG : Waiting for deletions to finish 2025/04/15 05:28:02 DEBUG : CopyDest/two: md5 = 3eee96df6d744ef01f474340ca0775aa OK 2025/04/15 05:28:02 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/04/15 05:28:02 DEBUG : one: Unchanged skipping 2025/04/15 05:28:03 DEBUG : two: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/04/15 05:28:04 INFO : two: Copied (server-side copy) 2025/04/15 05:28:04 DEBUG : two: Destination found in --copy-dest, using server-side copy 2025/04/15 05:28:04 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dovuxej0zopu/dst': Waiting for checks to finish 2025/04/15 05:28:04 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dovuxej0zopu/dst': Waiting for transfers to finish 2025/04/15 05:28:04 DEBUG : Waiting for deletions to finish 2025/04/15 05:28:04 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/04/15 05:28:04 DEBUG : one: Unchanged skipping 2025/04/15 05:28:04 DEBUG : two: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/04/15 05:28:04 DEBUG : two: Unchanged skipping 2025/04/15 05:28:04 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dovuxej0zopu/dst': Waiting for checks to finish 2025/04/15 05:28:04 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dovuxej0zopu/dst': Waiting for transfers to finish 2025/04/15 05:28:04 DEBUG : Waiting for deletions to finish 2025/04/15 05:28:04 INFO : There was nothing to transfer 2025/04/15 05:28:06 DEBUG : CopyDest/three: md5 = 8559afb9fbad82d86909b5b02c3a0c11 OK 2025/04/15 05:28:07 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/04/15 05:28:07 DEBUG : one: Unchanged skipping 2025/04/15 05:28:07 DEBUG : three: Sizes differ (src 7 vs dst 5) 2025/04/15 05:28:07 DEBUG : three: Destination not found in --copy-dest 2025/04/15 05:28:07 DEBUG : three: Need to transfer - File not found at Destination 2025/04/15 05:28:07 DEBUG : two: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/04/15 05:28:07 DEBUG : two: Unchanged skipping 2025/04/15 05:28:07 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dovuxej0zopu/dst': Waiting for checks to finish 2025/04/15 05:28:07 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dovuxej0zopu/dst': Waiting for transfers to finish 2025/04/15 05:28:08 DEBUG : three: md5 = 963cb436315ed12935c13560f9333c60 OK 2025/04/15 05:28:08 INFO : three: Copied (new) 2025/04/15 05:28:08 DEBUG : Waiting for deletions to finish 2025/04/15 05:28:13 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "b6jdmn2b1adrhc8vikh7edr9os" 2025/04/15 05:28:13 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" 2025/04/15 05:28:13 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k" 2025/04/15 05:28:13 DEBUG : d09o6po3f7bm6ce32vdgs8h9ls: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" 2025/04/15 05:28:13 DEBUG : d09o6po3f7bm6ce32vdgs8h9ls: Rmdir: contains trashed file: "b6jdmn2b1adrhc8vikh7edr9os" 2025/04/15 05:28:13 DEBUG : d09o6po3f7bm6ce32vdgs8h9ls: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k" 2025/04/15 05:28:14 DEBUG : s6dbk3lfi7c9kfvo6j7bla9m0g: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" --- PASS: TestSyncCopyDest (32.25s) === RUN TestSyncBackupDir run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dovuxej0zopu'", Local "Local file system at /tmp/rclone1859944754", Modify Window "1ms" 2025/04/15 05:28:17 DEBUG : dst/one: md5 = aa021ba45723822caed2d8361fe90737 OK 2025/04/15 05:28:18 DEBUG : dst/two: md5 = 8983837f1912e4b52c23e7a93761b465 OK 2025/04/15 05:28:20 DEBUG : dst/three.txt: md5 = f14875f260780f63b94410bcb2dd6135 OK 2025/04/15 05:28:20 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-dovuxej0zopu/dst" 2025/04/15 05:28:20 DEBUG : Creating backend with remote "TestDrive:crypt/smlh8e653n38ba8jg0ed6f8tncp8o8vm9ic9r24gp4sdufv0g7r0/31u3jie661vd5p8j7rtc3hgbh0" 2025/04/15 05:28:21 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-dovuxej0zopu/backup" 2025/04/15 05:28:21 DEBUG : Creating backend with remote "TestDrive:crypt/smlh8e653n38ba8jg0ed6f8tncp8o8vm9ic9r24gp4sdufv0g7r0/1nrff024r7pq65ecp72fc28jb0" 2025/04/15 05:28:23 DEBUG : one: Sizes differ (src 4 vs dst 3) 2025/04/15 05:28:23 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/15 05:28:23 DEBUG : two: Unchanged skipping 2025/04/15 05:28:23 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dovuxej0zopu/dst': Waiting for checks to finish 2025/04/15 05:28:24 INFO : one: Moved (server-side) 2025/04/15 05:28:24 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dovuxej0zopu/dst': Waiting for transfers to finish 2025/04/15 05:28:25 DEBUG : one: md5 = 8f36e2dac4cf5147b15235a830369cb2 OK 2025/04/15 05:28:25 INFO : one: Copied (new) 2025/04/15 05:28:25 DEBUG : Waiting for deletions to finish 2025/04/15 05:28:26 INFO : three.txt: Moved (server-side) 2025/04/15 05:28:26 INFO : three.txt: Moved into backup dir 2025/04/15 05:28:28 DEBUG : dst/three.txt: md5 = 0c56ddb171a81846e84ef365e9d4d363 OK 2025/04/15 05:28:29 DEBUG : one: Sizes differ (src 5 vs dst 4) 2025/04/15 05:28:29 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/15 05:28:29 DEBUG : two: Unchanged skipping 2025/04/15 05:28:29 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dovuxej0zopu/dst': Waiting for checks to finish 2025/04/15 05:28:30 INFO : one: Deleted 2025/04/15 05:28:30 INFO : one: Moved (server-side) 2025/04/15 05:28:30 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dovuxej0zopu/dst': Waiting for transfers to finish 2025/04/15 05:28:32 DEBUG : one: md5 = 1f117a424ff791027f127e25060b6027 OK 2025/04/15 05:28:32 INFO : one: Copied (new) 2025/04/15 05:28:32 DEBUG : Waiting for deletions to finish 2025/04/15 05:28:32 INFO : three.txt: Deleted 2025/04/15 05:28:33 INFO : three.txt: Moved (server-side) 2025/04/15 05:28:33 INFO : three.txt: Moved into backup dir 2025/04/15 05:28:36 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" 2025/04/15 05:28:36 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k" 2025/04/15 05:28:37 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "tr2hj63d80ftlmvm6a952snjcc" 2025/04/15 05:28:37 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" 2025/04/15 05:28:37 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" 2025/04/15 05:28:37 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "tr2hj63d80ftlmvm6a952snjcc" --- PASS: TestSyncBackupDir (22.63s) === RUN TestSyncBackupDirWithSuffix run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dovuxej0zopu'", Local "Local file system at /tmp/rclone1859944754", Modify Window "1ms" 2025/04/15 05:28:39 DEBUG : dst/one: md5 = 7d47e8b849093fd7393bb8245b0d6e88 OK 2025/04/15 05:28:41 DEBUG : dst/two: md5 = 96172804c4b157d005d49173d5c1a446 OK 2025/04/15 05:28:42 DEBUG : dst/three.txt: md5 = 75d43e17a28c9c4f1fe1799eb00e2878 OK 2025/04/15 05:28:43 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-dovuxej0zopu/dst" 2025/04/15 05:28:43 DEBUG : Creating backend with remote "TestDrive:crypt/smlh8e653n38ba8jg0ed6f8tncp8o8vm9ic9r24gp4sdufv0g7r0/31u3jie661vd5p8j7rtc3hgbh0" 2025/04/15 05:28:44 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-dovuxej0zopu/backup" 2025/04/15 05:28:44 DEBUG : Creating backend with remote "TestDrive:crypt/smlh8e653n38ba8jg0ed6f8tncp8o8vm9ic9r24gp4sdufv0g7r0/1nrff024r7pq65ecp72fc28jb0" 2025/04/15 05:28:45 DEBUG : one: Sizes differ (src 4 vs dst 3) 2025/04/15 05:28:45 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/15 05:28:45 DEBUG : two: Unchanged skipping 2025/04/15 05:28:45 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dovuxej0zopu/dst': Waiting for checks to finish 2025/04/15 05:28:47 INFO : one: Moved (server-side) to: one.bak 2025/04/15 05:28:47 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dovuxej0zopu/dst': Waiting for transfers to finish 2025/04/15 05:28:48 DEBUG : one: md5 = bd5417f9550a27eea188a9d3cd862eeb OK 2025/04/15 05:28:48 INFO : one: Copied (new) 2025/04/15 05:28:48 DEBUG : Waiting for deletions to finish 2025/04/15 05:28:49 INFO : three.txt: Moved (server-side) to: three.txt.bak 2025/04/15 05:28:49 INFO : three.txt: Moved into backup dir 2025/04/15 05:28:51 DEBUG : dst/three.txt: md5 = 1f47c20621119057829b075649da23c8 OK 2025/04/15 05:28:51 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dovuxej0zopu/dst': Waiting for checks to finish 2025/04/15 05:28:51 DEBUG : one: Sizes differ (src 5 vs dst 4) 2025/04/15 05:28:51 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/15 05:28:51 DEBUG : two: Unchanged skipping 2025/04/15 05:28:52 INFO : one.bak: Deleted 2025/04/15 05:28:53 INFO : one: Moved (server-side) to: one.bak 2025/04/15 05:28:53 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dovuxej0zopu/dst': Waiting for transfers to finish 2025/04/15 05:28:54 DEBUG : one: md5 = 3551299ff65f44caff48a12ac4d96247 OK 2025/04/15 05:28:54 INFO : one: Copied (new) 2025/04/15 05:28:54 DEBUG : Waiting for deletions to finish 2025/04/15 05:28:55 INFO : three.txt.bak: Deleted 2025/04/15 05:28:55 INFO : three.txt: Moved (server-side) to: three.txt.bak 2025/04/15 05:28:55 INFO : three.txt: Moved into backup dir 2025/04/15 05:28:58 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" 2025/04/15 05:28:58 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k" 2025/04/15 05:28:59 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "sk91qgsqfn0r271r2ehsaoc20c" 2025/04/15 05:28:59 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "qltcak2uaegtmcoa8vijdppbp8" 2025/04/15 05:28:59 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "qltcak2uaegtmcoa8vijdppbp8" 2025/04/15 05:28:59 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "sk91qgsqfn0r271r2ehsaoc20c" --- PASS: TestSyncBackupDirWithSuffix (22.29s) === RUN TestSyncBackupDirWithSuffixKeepExtension run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dovuxej0zopu'", Local "Local file system at /tmp/rclone1859944754", Modify Window "1ms" 2025/04/15 05:29:02 DEBUG : dst/one: md5 = 7d9051211719396641067e7d68fe8541 OK 2025/04/15 05:29:03 DEBUG : dst/two: md5 = 684beb75e90786fcb10ce442bfacff16 OK 2025/04/15 05:29:04 DEBUG : dst/three.txt: md5 = 0ccba788113e97b19ef9299712eeb028 OK 2025/04/15 05:29:05 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-dovuxej0zopu/dst" 2025/04/15 05:29:05 DEBUG : Creating backend with remote "TestDrive:crypt/smlh8e653n38ba8jg0ed6f8tncp8o8vm9ic9r24gp4sdufv0g7r0/31u3jie661vd5p8j7rtc3hgbh0" 2025/04/15 05:29:05 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-dovuxej0zopu/backup" 2025/04/15 05:29:06 DEBUG : Creating backend with remote "TestDrive:crypt/smlh8e653n38ba8jg0ed6f8tncp8o8vm9ic9r24gp4sdufv0g7r0/1nrff024r7pq65ecp72fc28jb0" 2025/04/15 05:29:07 DEBUG : one: Sizes differ (src 4 vs dst 3) 2025/04/15 05:29:07 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/15 05:29:07 DEBUG : two: Unchanged skipping 2025/04/15 05:29:07 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dovuxej0zopu/dst': Waiting for checks to finish 2025/04/15 05:29:09 INFO : one: Moved (server-side) to: one-2019-01-01 2025/04/15 05:29:09 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dovuxej0zopu/dst': Waiting for transfers to finish 2025/04/15 05:29:10 DEBUG : one: md5 = 2b2d6f0c94b4cb0b2dfc116e407b343f OK 2025/04/15 05:29:10 INFO : one: Copied (new) 2025/04/15 05:29:10 DEBUG : Waiting for deletions to finish 2025/04/15 05:29:11 INFO : three.txt: Moved (server-side) to: three-2019-01-01.txt 2025/04/15 05:29:11 INFO : three.txt: Moved into backup dir 2025/04/15 05:29:13 DEBUG : dst/three.txt: md5 = 0934bf47e8cf3a75ce4197989a34c50a OK 2025/04/15 05:29:14 DEBUG : one: Sizes differ (src 5 vs dst 4) 2025/04/15 05:29:14 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/15 05:29:14 DEBUG : two: Unchanged skipping 2025/04/15 05:29:14 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dovuxej0zopu/dst': Waiting for checks to finish 2025/04/15 05:29:14 INFO : one-2019-01-01: Deleted 2025/04/15 05:29:15 INFO : one: Moved (server-side) to: one-2019-01-01 2025/04/15 05:29:15 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dovuxej0zopu/dst': Waiting for transfers to finish 2025/04/15 05:29:16 DEBUG : one: md5 = 49355e2278a81dcfe24d8145b85da202 OK 2025/04/15 05:29:16 INFO : one: Copied (new) 2025/04/15 05:29:16 DEBUG : Waiting for deletions to finish 2025/04/15 05:29:17 INFO : three-2019-01-01.txt: Deleted 2025/04/15 05:29:17 INFO : three.txt: Moved (server-side) to: three-2019-01-01.txt 2025/04/15 05:29:17 INFO : three.txt: Moved into backup dir 2025/04/15 05:29:21 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" 2025/04/15 05:29:21 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k" 2025/04/15 05:29:21 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "jcjl1bv3ep0v8kt35lqql1co90" 2025/04/15 05:29:21 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "qtq2f6qq4lgpsmj88vb7147qje3prudmtfdtr2342fth58vo9a50" 2025/04/15 05:29:21 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "jcjl1bv3ep0v8kt35lqql1co90" 2025/04/15 05:29:21 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "qtq2f6qq4lgpsmj88vb7147qje3prudmtfdtr2342fth58vo9a50" --- PASS: TestSyncBackupDirWithSuffixKeepExtension (22.30s) === RUN TestSyncBackupDirSuffixOnly run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dovuxej0zopu'", Local "Local file system at /tmp/rclone1859944754", Modify Window "1ms" 2025/04/15 05:29:24 DEBUG : dst/one: md5 = aa4a3a640c34230814dcdbbfda6fb030 OK 2025/04/15 05:29:25 DEBUG : dst/two: md5 = 20d8dd838fa289c45889149ac7e9ea41 OK 2025/04/15 05:29:27 DEBUG : dst/three.txt: md5 = 75e25a06384beb0da937642f5f9b3a72 OK 2025/04/15 05:29:27 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-dovuxej0zopu/dst" 2025/04/15 05:29:27 DEBUG : Creating backend with remote "TestDrive:crypt/smlh8e653n38ba8jg0ed6f8tncp8o8vm9ic9r24gp4sdufv0g7r0/31u3jie661vd5p8j7rtc3hgbh0" 2025/04/15 05:29:28 DEBUG : one: Sizes differ (src 4 vs dst 3) 2025/04/15 05:29:28 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/15 05:29:28 DEBUG : two: Unchanged skipping 2025/04/15 05:29:28 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dovuxej0zopu/dst': Waiting for checks to finish 2025/04/15 05:29:29 INFO : one: Moved (server-side) to: one.bak 2025/04/15 05:29:29 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dovuxej0zopu/dst': Waiting for transfers to finish 2025/04/15 05:29:30 DEBUG : one: md5 = c4f3cfb2fd12988ab937e9a1a4ff068c OK 2025/04/15 05:29:30 INFO : one: Copied (new) 2025/04/15 05:29:30 DEBUG : Waiting for deletions to finish 2025/04/15 05:29:31 INFO : three.txt: Moved (server-side) to: three.txt.bak 2025/04/15 05:29:31 INFO : three.txt: Moved into backup dir 2025/04/15 05:29:33 DEBUG : dst/three.txt: md5 = bbe3fdf8dd5948f83da3dd9215e6c204 OK 2025/04/15 05:29:34 DEBUG : three.txt.bak: Excluded (Path Filter) 2025/04/15 05:29:34 DEBUG : one.bak: Excluded (Path Filter) 2025/04/15 05:29:34 DEBUG : one: Sizes differ (src 5 vs dst 4) 2025/04/15 05:29:34 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/15 05:29:34 DEBUG : two: Unchanged skipping 2025/04/15 05:29:34 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dovuxej0zopu/dst': Waiting for checks to finish 2025/04/15 05:29:35 INFO : one.bak: Deleted 2025/04/15 05:29:35 INFO : one: Moved (server-side) to: one.bak 2025/04/15 05:29:35 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dovuxej0zopu/dst': Waiting for transfers to finish 2025/04/15 05:29:37 DEBUG : one: md5 = dfc024ff5253202044e6fb52be9872d1 OK 2025/04/15 05:29:37 INFO : one: Copied (new) 2025/04/15 05:29:37 DEBUG : Waiting for deletions to finish 2025/04/15 05:29:37 INFO : three.txt.bak: Deleted 2025/04/15 05:29:38 INFO : three.txt: Moved (server-side) to: three.txt.bak 2025/04/15 05:29:38 INFO : three.txt: Moved into backup dir 2025/04/15 05:29:41 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" 2025/04/15 05:29:41 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "sk91qgsqfn0r271r2ehsaoc20c" 2025/04/15 05:29:41 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "qltcak2uaegtmcoa8vijdppbp8" 2025/04/15 05:29:41 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "sk91qgsqfn0r271r2ehsaoc20c" 2025/04/15 05:29:41 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k" 2025/04/15 05:29:41 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "qltcak2uaegtmcoa8vijdppbp8" --- PASS: TestSyncBackupDirSuffixOnly (19.60s) === RUN TestSyncSuffix run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dovuxej0zopu'", Local "Local file system at /tmp/rclone1859944754", Modify Window "1ms" 2025/04/15 05:29:44 DEBUG : dst/one: md5 = b157d84db4ee264be7bdb1c2d4a3d819 OK 2025/04/15 05:29:45 DEBUG : dst/two: md5 = b0818f604c1c94edcd780eadce34dabf OK 2025/04/15 05:29:47 DEBUG : dst/three.txt: md5 = 100e6f807d45bf40c2a6f1eb8e8d345b OK 2025/04/15 05:29:47 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-dovuxej0zopu/dst" 2025/04/15 05:29:47 DEBUG : Creating backend with remote "TestDrive:crypt/smlh8e653n38ba8jg0ed6f8tncp8o8vm9ic9r24gp4sdufv0g7r0/31u3jie661vd5p8j7rtc3hgbh0" 2025/04/15 05:29:48 DEBUG : one: Sizes differ (src 4 vs dst 3) 2025/04/15 05:29:49 INFO : one: Moved (server-side) to: one.bak 2025/04/15 05:29:50 DEBUG : one: md5 = 0c819a56baa35670cc9d9cbda3b7b272 OK 2025/04/15 05:29:50 INFO : one: Copied (new) 2025/04/15 05:29:50 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/15 05:29:50 DEBUG : two: Unchanged skipping 2025/04/15 05:29:51 DEBUG : three.txt: Sizes differ (src 6 vs dst 5) 2025/04/15 05:29:51 INFO : three.txt: Moved (server-side) to: three.txt.bak 2025/04/15 05:29:53 DEBUG : three.txt: md5 = 78d62d8fd5a388d999821dcad6a8e27b OK 2025/04/15 05:29:53 INFO : three.txt: Copied (new) 2025/04/15 05:29:54 DEBUG : one: Sizes differ (src 5 vs dst 4) 2025/04/15 05:29:55 INFO : one.bak: Deleted 2025/04/15 05:29:56 INFO : one: Moved (server-side) to: one.bak 2025/04/15 05:29:57 DEBUG : one: md5 = 7f26d667204234cafed32b627a950e80 OK 2025/04/15 05:29:57 INFO : one: Copied (new) 2025/04/15 05:29:57 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/15 05:29:57 DEBUG : two: Unchanged skipping 2025/04/15 05:29:57 DEBUG : three.txt: Sizes differ (src 19 vs dst 6) 2025/04/15 05:29:58 INFO : three.txt.bak: Deleted 2025/04/15 05:29:59 INFO : three.txt: Moved (server-side) to: three.txt.bak 2025/04/15 05:30:00 DEBUG : three.txt: md5 = ef99fa2f50840ff973c42fb9a74ccfcc OK 2025/04/15 05:30:00 INFO : three.txt: Copied (new) 2025/04/15 05:30:03 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" 2025/04/15 05:30:03 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "tr2hj63d80ftlmvm6a952snjcc" 2025/04/15 05:30:03 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "qltcak2uaegtmcoa8vijdppbp8" 2025/04/15 05:30:03 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "sk91qgsqfn0r271r2ehsaoc20c" 2025/04/15 05:30:03 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k" 2025/04/15 05:30:03 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "qltcak2uaegtmcoa8vijdppbp8" 2025/04/15 05:30:03 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "sk91qgsqfn0r271r2ehsaoc20c" --- PASS: TestSyncSuffix (22.46s) === RUN TestSyncSuffixKeepExtension run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dovuxej0zopu'", Local "Local file system at /tmp/rclone1859944754", Modify Window "1ms" 2025/04/15 05:30:06 DEBUG : dst/one: md5 = 90375da20157acc50f37185577304fbd OK 2025/04/15 05:30:08 DEBUG : dst/two: md5 = 1181e053f4372dbfd27ee3e6b11d7e01 OK 2025/04/15 05:30:09 DEBUG : dst/three.txt: md5 = 75014526ed51d90c5434b629e6bd4c4f OK 2025/04/15 05:30:09 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-dovuxej0zopu/dst" 2025/04/15 05:30:09 DEBUG : Creating backend with remote "TestDrive:crypt/smlh8e653n38ba8jg0ed6f8tncp8o8vm9ic9r24gp4sdufv0g7r0/31u3jie661vd5p8j7rtc3hgbh0" 2025/04/15 05:30:10 DEBUG : one: Sizes differ (src 4 vs dst 3) 2025/04/15 05:30:11 INFO : one: Moved (server-side) to: one-2019-01-01 2025/04/15 05:30:12 DEBUG : one: md5 = 9d89945d0cc7279ade92c47fc1477fbc OK 2025/04/15 05:30:12 INFO : one: Copied (new) 2025/04/15 05:30:13 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/15 05:30:13 DEBUG : two: Unchanged skipping 2025/04/15 05:30:13 DEBUG : three.txt: Sizes differ (src 6 vs dst 5) 2025/04/15 05:30:14 INFO : three.txt: Moved (server-side) to: three-2019-01-01.txt 2025/04/15 05:30:15 DEBUG : three.txt: md5 = b39581953dde53f56c021b09e6ffffed OK 2025/04/15 05:30:15 INFO : three.txt: Copied (new) 2025/04/15 05:30:16 DEBUG : one: Sizes differ (src 5 vs dst 4) 2025/04/15 05:30:17 INFO : one-2019-01-01: Deleted 2025/04/15 05:30:17 INFO : one: Moved (server-side) to: one-2019-01-01 2025/04/15 05:30:19 DEBUG : one: md5 = aa2c23abf0deea621288ccbadd3b54b1 OK 2025/04/15 05:30:19 INFO : one: Copied (new) 2025/04/15 05:30:19 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/15 05:30:19 DEBUG : two: Unchanged skipping 2025/04/15 05:30:19 DEBUG : three.txt: Sizes differ (src 19 vs dst 6) 2025/04/15 05:30:20 INFO : three-2019-01-01.txt: Deleted 2025/04/15 05:30:21 INFO : three.txt: Moved (server-side) to: three-2019-01-01.txt 2025/04/15 05:30:22 DEBUG : three.txt: md5 = 33579e8b41823e39c886e40b9a1d7d5d OK 2025/04/15 05:30:22 INFO : three.txt: Copied (new) 2025/04/15 05:30:26 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" 2025/04/15 05:30:26 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "tr2hj63d80ftlmvm6a952snjcc" 2025/04/15 05:30:26 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "jcjl1bv3ep0v8kt35lqql1co90" 2025/04/15 05:30:26 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "jcjl1bv3ep0v8kt35lqql1co90" 2025/04/15 05:30:26 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k" 2025/04/15 05:30:26 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "qtq2f6qq4lgpsmj88vb7147qje3prudmtfdtr2342fth58vo9a50" 2025/04/15 05:30:26 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "qtq2f6qq4lgpsmj88vb7147qje3prudmtfdtr2342fth58vo9a50" --- PASS: TestSyncSuffixKeepExtension (22.39s) === RUN TestSyncUTFNorm run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dovuxej0zopu'", Local "Local file system at /tmp/rclone1859944754", Modify Window "1ms" 2025/04/15 05:30:28 DEBUG : Testêé: md5 = 4fd10f0da275b0ffdc2226d414ad214f OK 2025/04/15 05:30:28 DEBUG : Testêé: Sizes differ (src 14 vs dst 18) 2025/04/15 05:30:28 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dovuxej0zopu': Waiting for checks to finish 2025/04/15 05:30:28 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dovuxej0zopu': Waiting for transfers to finish 2025/04/15 05:30:30 DEBUG : Testêé: md5 = a17694671fb47de2e597ee9fec8c0f3d OK 2025/04/15 05:30:30 INFO : Testêé: Copied (replaced existing) to: Testêé 2025/04/15 05:30:30 DEBUG : Waiting for deletions to finish --- PASS: TestSyncUTFNorm (4.49s) === RUN TestSyncImmutable run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dovuxej0zopu'", Local "Local file system at /tmp/rclone1859944754", Modify Window "1ms" 2025/04/15 05:30:31 DEBUG : existing: Need to transfer - File not found at Destination 2025/04/15 05:30:31 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dovuxej0zopu': Waiting for checks to finish 2025/04/15 05:30:31 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dovuxej0zopu': Waiting for transfers to finish 2025/04/15 05:30:33 DEBUG : existing: md5 = b0fcb16121ef15917f1ef76a6bd2e01d OK 2025/04/15 05:30:33 INFO : existing: Copied (new) 2025/04/15 05:30:33 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dovuxej0zopu'", Local "Local file system at /tmp/rclone1859944754", Modify Window "1ms" 2025/04/15 05:30:33 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dovuxej0zopu': Waiting for checks to finish 2025/04/15 05:30:33 DEBUG : existing: Sizes differ (src 8 vs dst 6) 2025/04/15 05:30:33 ERROR : existing: Source and destination exist but do not match: immutable file modified 2025/04/15 05:30:33 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dovuxej0zopu': Waiting for transfers to finish 2025/04/15 05:30:33 ERROR : Encrypted drive 'TestCryptDrive:rclone-test-dovuxej0zopu': not deleting files as there were IO errors 2025/04/15 05:30:33 ERROR : Encrypted drive 'TestCryptDrive:rclone-test-dovuxej0zopu': not deleting directories as there were IO errors run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dovuxej0zopu'", Local "Local file system at /tmp/rclone1859944754", Modify Window "1ms" --- PASS: TestSyncImmutable (4.61s) === RUN TestSyncIgnoreCase run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dovuxej0zopu'", Local "Local file system at /tmp/rclone1859944754", Modify Window "1ms" 2025/04/15 05:30:37 DEBUG : EXISTING: md5 = 6635cb4d94cb397d1d58358fd42e2049 OK 2025/04/15 05:30:37 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dovuxej0zopu': Waiting for checks to finish 2025/04/15 05:30:37 DEBUG : existing: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/15 05:30:37 DEBUG : existing: Unchanged skipping 2025/04/15 05:30:37 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dovuxej0zopu': Waiting for transfers to finish 2025/04/15 05:30:37 DEBUG : Waiting for deletions to finish 2025/04/15 05:30:37 INFO : There was nothing to transfer --- PASS: TestSyncIgnoreCase (3.07s) === RUN TestFixCase run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dovuxej0zopu'", Local "Local file system at /tmp/rclone1859944754", Modify Window "1ms" sync_test.go:2635: Skipping test as local or remote are case-sensitive --- SKIP: TestFixCase (0.46s) === RUN TestMaxTransfer === RUN TestMaxTransfer/Hard run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dovuxej0zopu'", Local "Local file system at /tmp/rclone1859944754", 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-dovuxej0zopu'", Local "Local file system at /tmp/rclone1859944754", 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-dovuxej0zopu'", Local "Local file system at /tmp/rclone1859944754", Modify Window "1ms" sync_test.go:2674: This test only runs on local --- PASS: TestMaxTransfer (1.49s) --- SKIP: TestMaxTransfer/Hard (0.58s) --- SKIP: TestMaxTransfer/Soft (0.46s) --- SKIP: TestMaxTransfer/Cautious (0.45s) === RUN TestSyncConcurrentDelete run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dovuxej0zopu'", Local "Local file system at /tmp/rclone1859944754", Modify Window "1ms" 2025/04/15 05:30:42 DEBUG : both0: md5 = e2a4dee939192cddee5c920fe1620812 OK 2025/04/15 05:30:43 DEBUG : only0: md5 = 4595ec46c01f00662b98014c8d5585fb OK 2025/04/15 05:30:45 DEBUG : both1: md5 = c53bbaceb88c715cec46789d0e84be0c OK 2025/04/15 05:30:46 DEBUG : only1: md5 = 86beba0555826485b4f0d7a539b98c82 OK 2025/04/15 05:30:47 DEBUG : both2: md5 = c367f238564c2e68b67e150636e49b03 OK 2025/04/15 05:30:49 DEBUG : only2: md5 = f4146d9f3d8cbc7af23abd743c41664a OK 2025/04/15 05:30:50 DEBUG : both3: md5 = 23affaf8cb101c0f78b90ff753f14170 OK 2025/04/15 05:30:52 DEBUG : only3: md5 = 0776234f8062edfdc848afb5427e41d9 OK 2025/04/15 05:30:53 DEBUG : both4: md5 = 1c1d84983a327e60329e89dc9d86f16a OK 2025/04/15 05:30:54 DEBUG : only4: md5 = 311427eb5dbfe6e0853fe7e683fb070b OK 2025/04/15 05:30:56 DEBUG : both5: md5 = 073da87ff968698e78266b9c3bce6f85 OK 2025/04/15 05:30:57 DEBUG : only5: md5 = a730c1eee44191278a255d8f013333ec OK 2025/04/15 05:30:59 DEBUG : both6: md5 = 81821eb8612b4552b472ffa7ba4be097 OK 2025/04/15 05:31:00 DEBUG : only6: md5 = 93a9acb66e3a799f1da032eb3f24f5b7 OK 2025/04/15 05:31:01 DEBUG : both7: md5 = de72d3b7e732f287f3c9a25a6f198d26 OK 2025/04/15 05:31:02 DEBUG : only7: md5 = 6691dacc55553ef9a43d19f350e9a208 OK 2025/04/15 05:31:04 DEBUG : both8: md5 = 999cb377ffab97af2d4c3353c80c4a98 OK 2025/04/15 05:31:05 DEBUG : only8: md5 = 2cc1c0104aae5b0a6e195dd7bd6b6db5 OK 2025/04/15 05:31:07 DEBUG : both9: md5 = b3be27ea75ab7e70c66e71032c04ba4b OK 2025/04/15 05:31:08 DEBUG : only9: md5 = 3971cfa474031c7d3609a47b734cacd8 OK 2025/04/15 05:31:09 DEBUG : both10: md5 = 25457787b5ba02abede0e29441fd4b9f OK 2025/04/15 05:31:11 DEBUG : only10: md5 = edbb4ff44080ebed40af2b7413ba3d1d OK 2025/04/15 05:31:12 DEBUG : both11: md5 = fb59f5701e48315c9901514480f744b3 OK 2025/04/15 05:31:13 DEBUG : only11: md5 = 22376d44e9b47722484080f382ee79b4 OK 2025/04/15 05:31:15 DEBUG : both12: md5 = 956768c1ce26f49bfef804ff5820848f OK 2025/04/15 05:31:16 DEBUG : only12: md5 = 648f8e8ce6259bfb78ffa9782a0fab8b OK 2025/04/15 05:31:18 DEBUG : both13: md5 = 111f6a54ff9fbe17b208aaf1358a0323 OK 2025/04/15 05:31:19 DEBUG : only13: md5 = 8c237658b8ea98251cd60562814b266d OK 2025/04/15 05:31:20 DEBUG : both14: md5 = 661f7d0bd009fcaacb42d2e4338502dd OK 2025/04/15 05:31:22 DEBUG : only14: md5 = 1974248bbd4c5219678465c9ff97e2df OK 2025/04/15 05:31:23 DEBUG : both15: md5 = e23e0631a2d24d0fd45b4040227c8526 OK 2025/04/15 05:31:24 DEBUG : only15: md5 = eaec671f20d6ae7ae13a0d60e347a2b1 OK 2025/04/15 05:31:26 DEBUG : both16: md5 = db52120f847034ed9a4d90b864f23ef9 OK 2025/04/15 05:31:27 DEBUG : only16: md5 = cdc0d5a2650be2175d0a0d5dda623df1 OK 2025/04/15 05:31:28 DEBUG : both17: md5 = 4349d2e54c8f483560cf0324a9568b06 OK 2025/04/15 05:31:30 DEBUG : only17: md5 = b97e9a78a03174e3aafcc272f256bca4 OK 2025/04/15 05:31:31 DEBUG : both18: md5 = 077329454d26be86064a5941bc88f288 OK 2025/04/15 05:31:33 DEBUG : only18: md5 = 03d03baff426fe93bc42dd39f0313dad OK 2025/04/15 05:31:34 DEBUG : both19: md5 = b874a5ce41b1b3b1aa088f1a1590afa3 OK 2025/04/15 05:31:35 DEBUG : only19: md5 = 316383b237ef6abf52a2411cd9fecb2d OK 2025/04/15 05:31:36 DEBUG : both0: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/15 05:31:36 DEBUG : both1: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/15 05:31:36 DEBUG : both11: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/15 05:31:36 DEBUG : both10: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/15 05:31:36 DEBUG : both0: Unchanged skipping 2025/04/15 05:31:36 DEBUG : both12: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/15 05:31:36 DEBUG : both12: Unchanged skipping 2025/04/15 05:31:36 DEBUG : both13: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/15 05:31:36 DEBUG : both13: Unchanged skipping 2025/04/15 05:31:36 DEBUG : both14: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/15 05:31:36 DEBUG : both14: Unchanged skipping 2025/04/15 05:31:36 DEBUG : both15: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/15 05:31:36 DEBUG : both15: Unchanged skipping 2025/04/15 05:31:36 DEBUG : both16: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/15 05:31:36 DEBUG : both16: Unchanged skipping 2025/04/15 05:31:36 DEBUG : both17: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/15 05:31:36 DEBUG : both17: Unchanged skipping 2025/04/15 05:31:36 DEBUG : both18: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/15 05:31:36 DEBUG : both18: Unchanged skipping 2025/04/15 05:31:36 DEBUG : both19: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/15 05:31:36 DEBUG : both19: Unchanged skipping 2025/04/15 05:31:36 DEBUG : both2: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/15 05:31:36 DEBUG : both2: Unchanged skipping 2025/04/15 05:31:36 DEBUG : both3: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/15 05:31:36 DEBUG : both3: Unchanged skipping 2025/04/15 05:31:36 DEBUG : both4: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/15 05:31:36 DEBUG : both11: Unchanged skipping 2025/04/15 05:31:36 DEBUG : both5: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/15 05:31:36 DEBUG : both10: Unchanged skipping 2025/04/15 05:31:36 DEBUG : both6: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/15 05:31:36 DEBUG : both4: Unchanged skipping 2025/04/15 05:31:36 DEBUG : both1: Unchanged skipping 2025/04/15 05:31:36 DEBUG : both7: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/15 05:31:36 DEBUG : both8: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/15 05:31:36 DEBUG : both6: Unchanged skipping 2025/04/15 05:31:36 DEBUG : both9: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/15 05:31:36 DEBUG : both9: Unchanged skipping 2025/04/15 05:31:36 DEBUG : both7: Unchanged skipping 2025/04/15 05:31:36 DEBUG : both5: Unchanged skipping 2025/04/15 05:31:36 DEBUG : both8: Unchanged skipping 2025/04/15 05:31:36 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dovuxej0zopu': Waiting for checks to finish 2025/04/15 05:31:36 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dovuxej0zopu': Waiting for transfers to finish 2025/04/15 05:31:36 DEBUG : Waiting for deletions to finish 2025/04/15 05:31:37 INFO : only14: Deleted 2025/04/15 05:31:37 INFO : only11: Deleted 2025/04/15 05:31:37 INFO : only18: Deleted 2025/04/15 05:31:37 INFO : only7: Deleted 2025/04/15 05:31:37 INFO : only0: Deleted 2025/04/15 05:31:37 INFO : only9: Deleted 2025/04/15 05:31:37 INFO : only2: Deleted 2025/04/15 05:31:37 INFO : only1: Deleted 2025/04/15 05:31:37 INFO : only5: Deleted 2025/04/15 05:31:37 INFO : only15: Deleted 2025/04/15 05:31:38 INFO : only4: Deleted 2025/04/15 05:31:38 INFO : only3: Deleted 2025/04/15 05:31:38 INFO : only6: Deleted 2025/04/15 05:31:38 INFO : only16: Deleted 2025/04/15 05:31:38 INFO : only13: Deleted 2025/04/15 05:31:38 INFO : only19: Deleted 2025/04/15 05:31:38 INFO : only10: Deleted 2025/04/15 05:31:38 INFO : only12: Deleted 2025/04/15 05:31:38 INFO : only8: Deleted 2025/04/15 05:31:39 INFO : only17: Deleted 2025/04/15 05:31:39 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dovuxej0zopu'", Local "Local file system at /tmp/rclone1859944754", Modify Window "1ms" --- PASS: TestSyncConcurrentDelete (68.47s) === RUN TestSyncConcurrentTruncate run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dovuxej0zopu'", Local "Local file system at /tmp/rclone1859944754", Modify Window "1ms" 2025/04/15 05:31:50 DEBUG : both0: md5 = 3a45cba7d08dc890ea6640286cfbbd0a OK 2025/04/15 05:31:52 DEBUG : only0: md5 = 9f4a18f3de75c8c391e6845772ba5cd9 OK 2025/04/15 05:31:53 DEBUG : both1: md5 = 7816bf0d1b6c64c3d01baf7fffd99f25 OK 2025/04/15 05:31:55 DEBUG : only1: md5 = d088af043507c5b0c0058c3a99bf97ae OK 2025/04/15 05:31:56 DEBUG : both2: md5 = 14f70deb42526a0649de7b2a3bca3197 OK 2025/04/15 05:31:58 DEBUG : only2: md5 = 1e4703df10d420f6085e25c4b83e55bb OK 2025/04/15 05:31:59 DEBUG : both3: md5 = 46929833eea0b120b3b295240e7d6788 OK 2025/04/15 05:32:00 DEBUG : only3: md5 = e789c2cf7e47516e7c37b243d920a376 OK 2025/04/15 05:32:02 DEBUG : both4: md5 = 4da988cf2a96a2063f51e0c85ab03762 OK 2025/04/15 05:32:03 DEBUG : only4: md5 = a918419d099c56900b40293a4aa79419 OK 2025/04/15 05:32:05 DEBUG : both5: md5 = 2baee0f0244b461c868eaee5818d761b OK 2025/04/15 05:32:06 DEBUG : only5: md5 = 7fe562d9190d4b20c48db232fc16b5f9 OK 2025/04/15 05:32:07 DEBUG : both6: md5 = e1dbcb6ac68b52e3794285177c3ab185 OK 2025/04/15 05:32:09 DEBUG : only6: md5 = b05b48853fc89cc4144593185a116e38 OK 2025/04/15 05:32:10 DEBUG : both7: md5 = af81f4ab65b11248dbef064b155c1833 OK 2025/04/15 05:32:12 DEBUG : only7: md5 = f76a752c8b4432ed58c94bfab4d6b961 OK 2025/04/15 05:32:13 DEBUG : both8: md5 = 7780f00ad080e675ee525936786c84c4 OK 2025/04/15 05:32:14 DEBUG : only8: md5 = f79a7568f5cda6263fa696970ad227ab OK 2025/04/15 05:32:16 DEBUG : both9: md5 = 8546006b0e3ed3d2bb75f7b19d16f3e3 OK 2025/04/15 05:32:17 DEBUG : only9: md5 = 7d89c6879d8f36f40f8c30ab1c6b17fb OK 2025/04/15 05:32:19 DEBUG : both10: md5 = 90dec224b9e4e5a5d629b43f551722ed OK 2025/04/15 05:32:20 DEBUG : only10: md5 = d7276102e55c301eb53921ac21db518e OK 2025/04/15 05:32:22 DEBUG : both11: md5 = 21d4db59ea84f08f74bd46cc74cb69d9 OK 2025/04/15 05:32:23 DEBUG : only11: md5 = d05c9a7739e5a1215dee7e4da3144ee1 OK 2025/04/15 05:32:24 DEBUG : both12: md5 = b02c32d5832904ceb4146aa58f014d06 OK 2025/04/15 05:32:26 DEBUG : only12: md5 = 8b9db41557271a5386865dfef6b3d351 OK 2025/04/15 05:32:27 DEBUG : both13: md5 = 301fd3c057b53acbc0396144cd3faa96 OK 2025/04/15 05:32:28 DEBUG : only13: md5 = 1fdee41039f048b38d9c538e14a5a98c OK 2025/04/15 05:32:30 DEBUG : both14: md5 = 46ff2583caaffb7adaf1c3e14114363f OK 2025/04/15 05:32:31 DEBUG : only14: md5 = d794d6ef33cf48b405ae6f6bcc029398 OK 2025/04/15 05:32:33 DEBUG : both15: md5 = 60376ee4ef3ca5b2f67a13078832e9e0 OK 2025/04/15 05:32:34 DEBUG : only15: md5 = 4b7c2d3c82036cb51e0c6e22365cad4e OK 2025/04/15 05:32:35 DEBUG : both16: md5 = e213073074eb14867d93585b95db5a05 OK 2025/04/15 05:32:37 DEBUG : only16: md5 = 0ba11c1bd8a47129a4b7ceb8633e2052 OK 2025/04/15 05:32:38 DEBUG : both17: md5 = 31a4a1b41477d16806986a79cfca83c7 OK 2025/04/15 05:32:40 DEBUG : only17: md5 = 44abecf2aea65c6437b1d5aebf971e49 OK 2025/04/15 05:32:41 DEBUG : both18: md5 = 97cfdb1dd9bcab74e8322bce2a282e4d OK 2025/04/15 05:32:43 DEBUG : only18: md5 = 7a09f2c9b36ea11c995973fe34a18a1d OK 2025/04/15 05:32:44 DEBUG : both19: md5 = 50488f8d8e2df7cefa2b9ee825717795 OK 2025/04/15 05:32:45 DEBUG : only19: md5 = db744981b7f099a5f26e9eb8a3bbb58f OK 2025/04/15 05:32:46 DEBUG : both0: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/15 05:32:46 DEBUG : both11: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/15 05:32:46 DEBUG : both1: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/15 05:32:46 DEBUG : both10: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/15 05:32:46 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dovuxej0zopu': Waiting for checks to finish 2025/04/15 05:32:46 DEBUG : both0: Unchanged skipping 2025/04/15 05:32:46 DEBUG : both12: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/15 05:32:46 DEBUG : both12: Unchanged skipping 2025/04/15 05:32:46 DEBUG : both13: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/15 05:32:46 DEBUG : both13: Unchanged skipping 2025/04/15 05:32:46 DEBUG : both14: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/15 05:32:46 DEBUG : both14: Unchanged skipping 2025/04/15 05:32:46 DEBUG : both15: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/15 05:32:46 DEBUG : both15: Unchanged skipping 2025/04/15 05:32:46 DEBUG : both16: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/15 05:32:46 DEBUG : both16: Unchanged skipping 2025/04/15 05:32:46 DEBUG : both17: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/15 05:32:46 DEBUG : both17: Unchanged skipping 2025/04/15 05:32:46 DEBUG : both18: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/15 05:32:46 DEBUG : both10: Unchanged skipping 2025/04/15 05:32:46 DEBUG : both19: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/15 05:32:46 DEBUG : both19: Unchanged skipping 2025/04/15 05:32:46 DEBUG : both2: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/15 05:32:46 DEBUG : both2: Unchanged skipping 2025/04/15 05:32:46 DEBUG : both3: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/15 05:32:46 DEBUG : both3: Unchanged skipping 2025/04/15 05:32:46 DEBUG : both4: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/15 05:32:46 DEBUG : both4: Unchanged skipping 2025/04/15 05:32:46 DEBUG : both5: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/15 05:32:46 DEBUG : both5: Unchanged skipping 2025/04/15 05:32:46 DEBUG : both6: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/15 05:32:46 DEBUG : both6: Unchanged skipping 2025/04/15 05:32:46 DEBUG : both7: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/15 05:32:46 DEBUG : both7: Unchanged skipping 2025/04/15 05:32:46 DEBUG : both8: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/15 05:32:46 DEBUG : both8: Unchanged skipping 2025/04/15 05:32:46 DEBUG : both9: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/15 05:32:46 DEBUG : both11: Unchanged skipping 2025/04/15 05:32:46 DEBUG : only0: Sizes differ (src 0 vs dst 6) 2025/04/15 05:32:46 DEBUG : both1: Unchanged skipping 2025/04/15 05:32:46 DEBUG : only1: Sizes differ (src 0 vs dst 6) 2025/04/15 05:32:46 DEBUG : both18: Unchanged skipping 2025/04/15 05:32:46 DEBUG : only10: Sizes differ (src 0 vs dst 6) 2025/04/15 05:32:46 DEBUG : only11: Sizes differ (src 0 vs dst 6) 2025/04/15 05:32:46 DEBUG : only12: Sizes differ (src 0 vs dst 6) 2025/04/15 05:32:46 DEBUG : only13: Sizes differ (src 0 vs dst 6) 2025/04/15 05:32:46 DEBUG : only14: Sizes differ (src 0 vs dst 6) 2025/04/15 05:32:46 DEBUG : only15: Sizes differ (src 0 vs dst 6) 2025/04/15 05:32:46 DEBUG : only16: Sizes differ (src 0 vs dst 6) 2025/04/15 05:32:46 DEBUG : only17: Sizes differ (src 0 vs dst 6) 2025/04/15 05:32:46 DEBUG : only18: Sizes differ (src 0 vs dst 6) 2025/04/15 05:32:46 DEBUG : only19: Sizes differ (src 0 vs dst 6) 2025/04/15 05:32:46 DEBUG : only2: Sizes differ (src 0 vs dst 6) 2025/04/15 05:32:46 DEBUG : only3: Sizes differ (src 0 vs dst 6) 2025/04/15 05:32:46 DEBUG : only4: Sizes differ (src 0 vs dst 6) 2025/04/15 05:32:46 DEBUG : only5: Sizes differ (src 0 vs dst 6) 2025/04/15 05:32:46 DEBUG : only6: Sizes differ (src 0 vs dst 6) 2025/04/15 05:32:46 DEBUG : only7: Sizes differ (src 0 vs dst 6) 2025/04/15 05:32:46 DEBUG : only8: Sizes differ (src 0 vs dst 6) 2025/04/15 05:32:46 DEBUG : only9: Sizes differ (src 0 vs dst 6) 2025/04/15 05:32:46 DEBUG : both9: Unchanged skipping 2025/04/15 05:32:46 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dovuxej0zopu': Waiting for transfers to finish 2025/04/15 05:32:47 DEBUG : only1: md5 = 9495c96c2653a71efc3b1ecd52eaa58d OK 2025/04/15 05:32:47 INFO : only1: Copied (replaced existing) 2025/04/15 05:32:47 DEBUG : only0: md5 = 89f545aae5a74dac9a2fc7a42c088cc5 OK 2025/04/15 05:32:47 INFO : only0: Copied (replaced existing) 2025/04/15 05:32:47 DEBUG : only11: md5 = b859db854158b2b0309a673954b52ab3 OK 2025/04/15 05:32:47 INFO : only11: Copied (replaced existing) 2025/04/15 05:32:47 DEBUG : only13: md5 = e553aaf0f138782f6c785f45053a1a5b OK 2025/04/15 05:32:47 INFO : only13: Copied (replaced existing) 2025/04/15 05:32:48 DEBUG : only15: md5 = 030df1c1f2eb75cc163cd05c385e33e0 OK 2025/04/15 05:32:48 INFO : only15: Copied (replaced existing) 2025/04/15 05:32:48 DEBUG : only14: md5 = 5979b76a949fd3e7e138d4f8816569a1 OK 2025/04/15 05:32:48 INFO : only14: Copied (replaced existing) 2025/04/15 05:32:48 DEBUG : only16: md5 = 2cae3043b250e80eb8efd9f47abf80fa OK 2025/04/15 05:32:48 INFO : only16: Copied (replaced existing) 2025/04/15 05:32:49 DEBUG : only17: md5 = 23d0ed485504ae94d38138a73cf30bed OK 2025/04/15 05:32:49 INFO : only17: Copied (replaced existing) 2025/04/15 05:32:49 DEBUG : only18: md5 = cfdd615f2fc83677725bfd02a85b05a7 OK 2025/04/15 05:32:49 INFO : only18: Copied (replaced existing) 2025/04/15 05:32:49 DEBUG : only2: md5 = 1700f389275924f115ef250368cb0e2c OK 2025/04/15 05:32:49 INFO : only2: Copied (replaced existing) 2025/04/15 05:32:49 DEBUG : only19: md5 = bf6735debd135ee524d2c8a28ce6da6c OK 2025/04/15 05:32:49 INFO : only19: Copied (replaced existing) 2025/04/15 05:32:50 DEBUG : only3: md5 = df19f702a7a249c4dbed27b13a65deff OK 2025/04/15 05:32:50 INFO : only3: Copied (replaced existing) 2025/04/15 05:32:50 DEBUG : only4: md5 = ca016fd49fa667790c9992482fedc7f5 OK 2025/04/15 05:32:50 INFO : only4: Copied (replaced existing) 2025/04/15 05:32:50 DEBUG : only5: md5 = 9fe239668b686d83adf862b1e462d691 OK 2025/04/15 05:32:50 INFO : only5: Copied (replaced existing) 2025/04/15 05:32:51 DEBUG : only6: md5 = 2705d04e49ff1dc56f656984891ae280 OK 2025/04/15 05:32:51 INFO : only6: Copied (replaced existing) 2025/04/15 05:32:51 DEBUG : only7: md5 = 2d7b372bb78f8df412874c1056afa9ca OK 2025/04/15 05:32:51 INFO : only7: Copied (replaced existing) 2025/04/15 05:32:51 DEBUG : only8: md5 = 283079e2ede1b8a3c53f4546aad18b8c OK 2025/04/15 05:32:51 INFO : only8: Copied (replaced existing) 2025/04/15 05:32:52 DEBUG : only9: md5 = 7098b620dbf834c52b6af7f2105771ed OK 2025/04/15 05:32:52 INFO : only9: Copied (replaced existing) 2025/04/15 05:32:52 DEBUG : only10: md5 = c594865e0e6d9d42f8b7f8b42d66a15e OK 2025/04/15 05:32:52 INFO : only10: Copied (replaced existing) 2025/04/15 05:32:52 DEBUG : only12: md5 = 835cf87ab7fbd27b06a21f0b718bdff4 OK 2025/04/15 05:32:52 INFO : only12: Copied (replaced existing) 2025/04/15 05:32:52 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dovuxej0zopu'", Local "Local file system at /tmp/rclone1859944754", Modify Window "1ms" --- PASS: TestSyncConcurrentTruncate (83.12s) === RUN TestSyncReplaceDirModTime run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dovuxej0zopu'", Local "Local file system at /tmp/rclone1859944754", Modify Window "1ms" 2025/04/15 05:33:12 DEBUG : empty_dir: Making directory with metadata 2025/04/15 05:33:12 INFO : empty_dir: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2025/04/15 05:33:12 DEBUG : empty_on_remote: Making directory with metadata 2025/04/15 05:33:12 INFO : empty_on_remote: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2025/04/15 05:33:12 DEBUG : empty_on_remote: Making directory with metadata 2025/04/15 05:33:13 INFO : empty_on_remote: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dovuxej0zopu'", Local "Local file system at /tmp/rclone1859944754", Modify Window "1ms" 2025/04/15 05:33:18 INFO : test_dir1: Set directory modification time (using DirSetModTime) 2025/04/15 05:33:18 INFO : test_dir2: Set directory modification time (using DirSetModTime) 2025/04/15 05:33:18 INFO : test_dir2/sub_dir: Set directory modification time (using DirSetModTime) 2025/04/15 05:33:18 INFO : empty_on_remote: Set directory modification time (using DirSetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dovuxej0zopu'", Local "Local file system at /tmp/rclone1859944754", Modify Window "1ms" 2025/04/15 05:33:27 DEBUG : heqj02jg0dcqlem7gl0500bvp0/24g2k8bseitblkmqnie1ibl2s8: Rmdir: contains trashed file: "633fmaa0qic3kv3cladnu11pto" 2025/04/15 05:33:28 DEBUG : heqj02jg0dcqlem7gl0500bvp0: Rmdir: contains trashed file: "24g2k8bseitblkmqnie1ibl2s8" 2025/04/15 05:33:28 DEBUG : gq68srrpl0nnf394bgf7dbu9kc: Rmdir: contains trashed file: "d26uovf0miqhd1mu3c9jbseq00" --- PASS: TestSyncReplaceDirModTime (18.43s) === RUN TestSyncReplaceDirModTimeWithEmptyDirs run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dovuxej0zopu'", Local "Local file system at /tmp/rclone1859944754", Modify Window "1ms" 2025/04/15 05:33:31 DEBUG : empty_dir: Making directory with metadata 2025/04/15 05:33:31 INFO : empty_dir: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2025/04/15 05:33:31 DEBUG : empty_on_remote: Making directory with metadata 2025/04/15 05:33:31 INFO : empty_on_remote: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2025/04/15 05:33:31 DEBUG : empty_on_remote: Making directory with metadata 2025/04/15 05:33:31 INFO : empty_on_remote: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dovuxej0zopu'", Local "Local file system at /tmp/rclone1859944754", Modify Window "1ms" 2025/04/15 05:33:36 INFO : test_dir1: Set directory modification time (using DirSetModTime) 2025/04/15 05:33:36 INFO : test_dir2: Set directory modification time (using DirSetModTime) 2025/04/15 05:33:36 INFO : test_dir2/sub_dir: Set directory modification time (using DirSetModTime) 2025/04/15 05:33:36 INFO : empty_on_remote: Set directory modification time (using DirSetModTime) 2025/04/15 05:33:36 INFO : empty_dir: Set directory modification time (using DirSetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dovuxej0zopu'", Local "Local file system at /tmp/rclone1859944754", Modify Window "1ms" 2025/04/15 05:33:45 DEBUG : heqj02jg0dcqlem7gl0500bvp0/24g2k8bseitblkmqnie1ibl2s8: Rmdir: contains trashed file: "633fmaa0qic3kv3cladnu11pto" 2025/04/15 05:33:46 DEBUG : heqj02jg0dcqlem7gl0500bvp0: Rmdir: contains trashed file: "24g2k8bseitblkmqnie1ibl2s8" 2025/04/15 05:33:47 DEBUG : gq68srrpl0nnf394bgf7dbu9kc: Rmdir: contains trashed file: "d26uovf0miqhd1mu3c9jbseq00" --- PASS: TestSyncReplaceDirModTimeWithEmptyDirs (19.07s) === RUN TestNothingToTransferWithEmptyDirs run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dovuxej0zopu'", Local "Local file system at /tmp/rclone1859944754", Modify Window "1ms" 2025/04/15 05:33:50 INFO : sub dir: Set directory modification time (using DirSetModTime) 2025/04/15 05:33:50 DEBUG : sub dir: Making directory with metadata 2025/04/15 05:33:50 INFO : sub dir: Made directory with metadata (mtime=2011-12-30T12:59:59Z) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dovuxej0zopu'", Local "Local file system at /tmp/rclone1859944754", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dovuxej0zopu'", Local "Local file system at /tmp/rclone1859944754", Modify Window "1ms" 2025/04/15 05:34:08 INFO : sub dir2: Set directory modification time (using DirSetModTime) 2025/04/15 05:34:08 INFO : sub dir2: Set directory modification time (using DirSetModTime) 2025/04/15 05:34:08 INFO : sub dirEmpty/sub dirEmpty2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2025/04/15 05:34:08 INFO : sub dirEmpty: Set directory modification time (using DirSetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dovuxej0zopu'", Local "Local file system at /tmp/rclone1859944754", Modify Window "1ms" 2025/04/15 05:34:23 DEBUG : gcsdkq814sbtppue42dpsbg8ug: Rmdir: contains trashed file: "sjuo65gk5q3r1199jselk9k9o0" 2025/04/15 05:34:23 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/37qp6d1gohacv723ij3brofbu8/i24n0ln37pa2hv8pctddeuh73o: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" 2025/04/15 05:34:24 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/37qp6d1gohacv723ij3brofbu8: Rmdir: contains trashed file: "i24n0ln37pa2hv8pctddeuh73o" 2025/04/15 05:34:25 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "37qp6d1gohacv723ij3brofbu8" 2025/04/15 05:34:26 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak" 2025/04/15 05:34:26 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak" 2025/04/15 05:34:27 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak" 2025/04/15 05:34:28 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak" 2025/04/15 05:34:28 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/4r13oncfa2rsrr82oqhsqv24ns: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" 2025/04/15 05:34:29 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc: Rmdir: contains trashed file: "4r13oncfa2rsrr82oqhsqv24ns" 2025/04/15 05:34:29 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak" 2025/04/15 05:34:30 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestNothingToTransferWithEmptyDirs (42.27s) === RUN TestNothingToTransferWithoutEmptyDirs run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dovuxej0zopu'", Local "Local file system at /tmp/rclone1859944754", Modify Window "1ms" 2025/04/15 05:34:32 INFO : sub dir: Set directory modification time (using DirSetModTime) 2025/04/15 05:34:32 DEBUG : sub dir: Making directory with metadata 2025/04/15 05:34:33 INFO : sub dir: Made directory with metadata (mtime=2011-12-30T12:59:59Z) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dovuxej0zopu'", Local "Local file system at /tmp/rclone1859944754", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dovuxej0zopu'", Local "Local file system at /tmp/rclone1859944754", Modify Window "1ms" 2025/04/15 05:34:54 INFO : sub dir2: Set directory modification time (using DirSetModTime) 2025/04/15 05:34:55 INFO : sub dir2: Set directory modification time (using DirSetModTime) 2025/04/15 05:34:55 INFO : sub dirEmpty/sub dirEmpty2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2025/04/15 05:34:55 INFO : sub dirEmpty: Set directory modification time (using DirSetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dovuxej0zopu'", Local "Local file system at /tmp/rclone1859944754", Modify Window "1ms" 2025/04/15 05:35:08 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/37qp6d1gohacv723ij3brofbu8/i24n0ln37pa2hv8pctddeuh73o: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" 2025/04/15 05:35:09 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/37qp6d1gohacv723ij3brofbu8: Rmdir: contains trashed file: "i24n0ln37pa2hv8pctddeuh73o" 2025/04/15 05:35:10 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "37qp6d1gohacv723ij3brofbu8" 2025/04/15 05:35:10 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak" 2025/04/15 05:35:11 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak" 2025/04/15 05:35:12 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak" 2025/04/15 05:35:13 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak" 2025/04/15 05:35:13 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/4r13oncfa2rsrr82oqhsqv24ns: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" 2025/04/15 05:35:14 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc: Rmdir: contains trashed file: "4r13oncfa2rsrr82oqhsqv24ns" 2025/04/15 05:35:14 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak" 2025/04/15 05:35:15 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestNothingToTransferWithoutEmptyDirs (44.98s) PASS 2025/04/15 05:35:17 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dovuxej0zopu': Purge remote "./sync.test -test.v -test.timeout 1h0m0s -remote TestCryptDrive: -verbose -fast-list" - Finished OK in 16m2.507163319s (try 1/5)