"./sync.test -test.v -test.timeout 1h0m0s -remote TestCryptDrive: -verbose -fast-list" - Starting (try 1/5) 2025/04/16 04:18:48 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-biqaqid5vuba" 2025/04/16 04:18:48 DEBUG : Using config file from "/home/rclone/.rclone.conf" 2025/04/16 04:18:49 DEBUG : Creating backend with remote "TestDrive:crypt/9a87j16mtkuji9mc0peqjph2mbqrqnv6bm2vtfn0gamjmakcjej0" 2025/04/16 04:18:50 DEBUG : Creating backend with remote "/tmp/rclone2020710954" === RUN TestPipe --- PASS: TestPipe (0.00s) === RUN TestPipeConcurrent --- PASS: TestPipeConcurrent (0.04s) === RUN TestPipeOrderBy === RUN TestPipeOrderBy/#00 === RUN TestPipeOrderBy/size === RUN TestPipeOrderBy/name === RUN TestPipeOrderBy/modtime === RUN TestPipeOrderBy/size,ascending === RUN TestPipeOrderBy/name,asc === RUN TestPipeOrderBy/modtime,ascending === RUN TestPipeOrderBy/size,descending === RUN TestPipeOrderBy/name,desc === RUN TestPipeOrderBy/modtime,descending === RUN TestPipeOrderBy/size,mixed,50 === RUN TestPipeOrderBy/size,mixed,51 --- PASS: TestPipeOrderBy (0.00s) --- PASS: TestPipeOrderBy/#00 (0.00s) --- PASS: TestPipeOrderBy/size (0.00s) --- PASS: TestPipeOrderBy/name (0.00s) --- PASS: TestPipeOrderBy/modtime (0.00s) --- PASS: TestPipeOrderBy/size,ascending (0.00s) --- PASS: TestPipeOrderBy/name,asc (0.00s) --- PASS: TestPipeOrderBy/modtime,ascending (0.00s) --- PASS: TestPipeOrderBy/size,descending (0.00s) --- PASS: TestPipeOrderBy/name,desc (0.00s) --- PASS: TestPipeOrderBy/modtime,descending (0.00s) --- PASS: TestPipeOrderBy/size,mixed,50 (0.00s) --- PASS: TestPipeOrderBy/size,mixed,51 (0.00s) === RUN TestNewLess === RUN TestNewLess/blankOK === RUN TestNewLess/tooManyParts === RUN TestNewLess/tooManyParts2 === RUN TestNewLess/badMixed === RUN TestNewLess/unknownComparison === RUN TestNewLess/unknownSortDirection === RUN TestNewLess/size === RUN TestNewLess/name === RUN TestNewLess/modtime === RUN TestNewLess/size,ascending === RUN TestNewLess/name,asc === RUN TestNewLess/modtime,ascending === RUN TestNewLess/size,descending === RUN TestNewLess/name,desc === RUN TestNewLess/modtime,descending === RUN TestNewLess/modtime,mixed === RUN TestNewLess/modtime,mixed,30 --- PASS: TestNewLess (0.00s) --- PASS: TestNewLess/blankOK (0.00s) --- PASS: TestNewLess/tooManyParts (0.00s) --- PASS: TestNewLess/tooManyParts2 (0.00s) --- PASS: TestNewLess/badMixed (0.00s) --- PASS: TestNewLess/unknownComparison (0.00s) --- PASS: TestNewLess/unknownSortDirection (0.00s) --- PASS: TestNewLess/size (0.00s) --- PASS: TestNewLess/name (0.00s) --- PASS: TestNewLess/modtime (0.00s) --- PASS: TestNewLess/size,ascending (0.00s) --- PASS: TestNewLess/name,asc (0.00s) --- PASS: TestNewLess/modtime,ascending (0.00s) --- PASS: TestNewLess/size,descending (0.00s) --- PASS: TestNewLess/name,desc (0.00s) --- PASS: TestNewLess/modtime,descending (0.00s) --- PASS: TestNewLess/modtime,mixed (0.00s) --- PASS: TestNewLess/modtime,mixed,30 (0.00s) === RUN TestRcCopy rc_test.go:16: Skipping test on non local remote --- SKIP: TestRcCopy (0.00s) === RUN TestRcMove rc_test.go:16: Skipping test on non local remote --- SKIP: TestRcMove (0.00s) === RUN TestRcSync rc_test.go:16: Skipping test on non local remote --- SKIP: TestRcSync (0.00s) === RUN TestCopyWithDryRun run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-biqaqid5vuba'", Local "Local file system at /tmp/rclone2020710954", Modify Window "1ms" 2025/04/16 04:18:51 DEBUG : Added delayed dir = "sub dir", newDst= 2025/04/16 04:18:51 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2025/04/16 04:18:51 NOTICE: sub dir/hello world: Skipped copy as --dry-run is set (size 11) 2025/04/16 04:18:51 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-biqaqid5vuba': Waiting for checks to finish 2025/04/16 04:18:51 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-biqaqid5vuba': Waiting for transfers to finish 2025/04/16 04:18:51 NOTICE: sub dir: Skipped set directory modification time as --dry-run is set run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-biqaqid5vuba'", Local "Local file system at /tmp/rclone2020710954", Modify Window "1ms" --- PASS: TestCopyWithDryRun (2.15s) === RUN TestCopy run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-biqaqid5vuba'", Local "Local file system at /tmp/rclone2020710954", Modify Window "1ms" 2025/04/16 04:18:52 INFO : sub dir: Set directory modification time (using DirSetModTime) 2025/04/16 04:18:52 DEBUG : Added delayed dir = "sub dir", newDst= 2025/04/16 04:18:52 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2025/04/16 04:18:52 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-biqaqid5vuba': Waiting for checks to finish 2025/04/16 04:18:52 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-biqaqid5vuba': Waiting for transfers to finish 2025/04/16 04:18:54 DEBUG : sub dir/hello world: md5 = a1d2be3320e84a6c3dc7c22ae059647a OK 2025/04/16 04:18:54 INFO : sub dir/hello world: Copied (new) 2025/04/16 04:18:55 INFO : sub dir: Set directory modification time (using DirSetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-biqaqid5vuba'", Local "Local file system at /tmp/rclone2020710954", Modify Window "1ms" 2025/04/16 04:18:57 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestCopy (5.93s) === RUN TestCopyMetadata run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-biqaqid5vuba'", Local "Local file system at /tmp/rclone2020710954", Modify Window "1ms" 2025/04/16 04:18:58 DEBUG : metadata sub dir: Making directory with metadata 2025/04/16 04:18:58 INFO : metadata sub dir: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2025/04/16 04:18:58 DEBUG : empty metadata sub dir: Making directory with metadata 2025/04/16 04:18:58 INFO : empty metadata sub dir: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2025/04/16 04:18:58 DEBUG : Local file system at /tmp/rclone2020710954: File to upload is small (21 bytes), uploading instead of streaming 2025/04/16 04:18:58 DEBUG : metadata sub dir/hello metadata world: md5 = baa7a013449dbba2b1ed02b5cfb4e1a2 OK 2025/04/16 04:18:58 DEBUG : metadata sub dir/hello metadata world: Size and md5 of src and dst objects identical 2025/04/16 04:18:58 INFO : metadata sub dir: Set directory modification time (using DirSetModTime) 2025/04/16 04:18:58 DEBUG : Google drive root 'crypt/9a87j16mtkuji9mc0peqjph2mbqrqnv6bm2vtfn0gamjmakcjej0': Skipping btime metadata as can't update it on an existing file: 2025-04-16T04:18:58.188523125Z 2025/04/16 04:18:59 INFO : empty metadata sub dir: Updated directory metadata 2025/04/16 04:18:59 DEBUG : Google drive root 'crypt/9a87j16mtkuji9mc0peqjph2mbqrqnv6bm2vtfn0gamjmakcjej0': Skipping btime metadata as can't update it on an existing file: 2025-04-16T04:18:58.188523125Z 2025/04/16 04:18:59 INFO : metadata sub dir: Updated directory metadata 2025/04/16 04:18:59 DEBUG : metadata sub dir/hello metadata world: Need to transfer - File not found at Destination 2025/04/16 04:18:59 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-biqaqid5vuba': Waiting for checks to finish 2025/04/16 04:18:59 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-biqaqid5vuba': Waiting for transfers to finish 2025/04/16 04:19:01 DEBUG : metadata sub dir/hello metadata world: md5 = 56333de3f4775f83676e1579a7e6c097 OK 2025/04/16 04:19:01 INFO : metadata sub dir/hello metadata world: Copied (new) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-biqaqid5vuba'", Local "Local file system at /tmp/rclone2020710954", Modify Window "1ms" 2025/04/16 04:19:03 DEBUG : fg45q1rm3kh00nmmkk4m6ihmrcnel1p7551kqhjr9bk2gtd2gbf0: Rmdir: contains trashed file: "dmuvulfij81f693ur0f1vvbvq9v6iscp56daas3m51n9li5e3470" --- PASS: TestCopyMetadata (7.52s) === RUN TestCopyMetadataNoEmptyDirs run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-biqaqid5vuba'", Local "Local file system at /tmp/rclone2020710954", Modify Window "1ms" 2025/04/16 04:19:05 DEBUG : metadata sub dir: Making directory with metadata 2025/04/16 04:19:05 INFO : metadata sub dir: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2025/04/16 04:19:05 DEBUG : empty metadata sub dir: Making directory with metadata 2025/04/16 04:19:05 INFO : empty metadata sub dir: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2025/04/16 04:19:05 DEBUG : Local file system at /tmp/rclone2020710954: File to upload is small (21 bytes), uploading instead of streaming 2025/04/16 04:19:05 DEBUG : metadata sub dir/hello metadata world: md5 = baa7a013449dbba2b1ed02b5cfb4e1a2 OK 2025/04/16 04:19:05 DEBUG : metadata sub dir/hello metadata world: Size and md5 of src and dst objects identical 2025/04/16 04:19:05 INFO : metadata sub dir: Set directory modification time (using DirSetModTime) 2025/04/16 04:19:05 DEBUG : Added delayed dir = "empty metadata sub dir", newDst= 2025/04/16 04:19:05 DEBUG : Added delayed dir = "metadata sub dir", newDst= 2025/04/16 04:19:05 DEBUG : metadata sub dir/hello metadata world: Need to transfer - File not found at Destination 2025/04/16 04:19:05 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-biqaqid5vuba': Waiting for checks to finish 2025/04/16 04:19:05 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-biqaqid5vuba': Waiting for transfers to finish 2025/04/16 04:19:08 DEBUG : metadata sub dir/hello metadata world: md5 = aced6e10782232a2056f408a362f8e2a OK 2025/04/16 04:19:08 INFO : metadata sub dir/hello metadata world: Copied (new) 2025/04/16 04:19:08 DEBUG : Google drive root 'crypt/9a87j16mtkuji9mc0peqjph2mbqrqnv6bm2vtfn0gamjmakcjej0': Skipping btime metadata as can't update it on an existing file: 2025-04-16T04:19:05.704514885Z 2025/04/16 04:19:08 INFO : metadata sub dir: Updated directory metadata run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-biqaqid5vuba'", Local "Local file system at /tmp/rclone2020710954", Modify Window "1ms" 2025/04/16 04:19:11 DEBUG : fg45q1rm3kh00nmmkk4m6ihmrcnel1p7551kqhjr9bk2gtd2gbf0: Rmdir: contains trashed file: "dmuvulfij81f693ur0f1vvbvq9v6iscp56daas3m51n9li5e3470" --- PASS: TestCopyMetadataNoEmptyDirs (6.70s) === RUN TestCopyMissingDirectory run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-biqaqid5vuba'", Local "Local file system at /tmp/rclone2020710954", Modify Window "1ms" 2025/04/16 04:19:12 DEBUG : Creating backend with remote "/non-existing" 2025/04/16 04:19:12 ERROR : Local file system at /non-existing: error reading source root directory: directory not found 2025/04/16 04:19:12 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-biqaqid5vuba': Waiting for checks to finish 2025/04/16 04:19:12 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-biqaqid5vuba': Waiting for transfers to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-biqaqid5vuba'", Local "Local file system at /tmp/rclone2020710954", Modify Window "1ms" --- PASS: TestCopyMissingDirectory (1.11s) === RUN TestCopyNoTraverse run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-biqaqid5vuba'", Local "Local file system at /tmp/rclone2020710954", Modify Window "1ms" 2025/04/16 04:19:13 DEBUG : Added delayed dir = "sub dir", newDst= 2025/04/16 04:19:13 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2025/04/16 04:19:13 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-biqaqid5vuba': Waiting for checks to finish 2025/04/16 04:19:13 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-biqaqid5vuba': Waiting for transfers to finish 2025/04/16 04:19:15 DEBUG : sub dir/hello world: md5 = 655a825587fda37206578f3a7a2803dd OK 2025/04/16 04:19:15 INFO : sub dir/hello world: Copied (new) 2025/04/16 04:19:16 INFO : sub dir: Set directory modification time (using DirSetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-biqaqid5vuba'", Local "Local file system at /tmp/rclone2020710954", Modify Window "1ms" 2025/04/16 04:19:18 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestCopyNoTraverse (5.59s) === RUN TestCopyCheckFirst run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-biqaqid5vuba'", Local "Local file system at /tmp/rclone2020710954", Modify Window "1ms" 2025/04/16 04:19:19 INFO : Encrypted drive 'TestCryptDrive:rclone-test-biqaqid5vuba': Running all checks before starting transfers 2025/04/16 04:19:19 DEBUG : Added delayed dir = "sub dir", newDst= 2025/04/16 04:19:19 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2025/04/16 04:19:19 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-biqaqid5vuba': Waiting for checks to finish 2025/04/16 04:19:19 INFO : Encrypted drive 'TestCryptDrive:rclone-test-biqaqid5vuba': Checks finished, now starting transfers 2025/04/16 04:19:19 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-biqaqid5vuba': Waiting for transfers to finish 2025/04/16 04:19:21 DEBUG : sub dir/hello world: md5 = 3ada9d348a83eb4c67fc9c64983b64e3 OK 2025/04/16 04:19:21 INFO : sub dir/hello world: Copied (new) 2025/04/16 04:19:21 INFO : sub dir: Set directory modification time (using DirSetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-biqaqid5vuba'", Local "Local file system at /tmp/rclone2020710954", Modify Window "1ms" 2025/04/16 04:19:23 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestCopyCheckFirst (5.77s) === RUN TestSyncNoTraverse run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-biqaqid5vuba'", Local "Local file system at /tmp/rclone2020710954", Modify Window "1ms" 2025/04/16 04:19:24 ERROR : Ignoring --no-traverse with sync 2025/04/16 04:19:25 DEBUG : Added delayed dir = "sub dir", newDst= 2025/04/16 04:19:25 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2025/04/16 04:19:25 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-biqaqid5vuba': Waiting for checks to finish 2025/04/16 04:19:25 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-biqaqid5vuba': Waiting for transfers to finish 2025/04/16 04:19:27 DEBUG : sub dir/hello world: md5 = 4567ca51953b841385709cb1f3dc2117 OK 2025/04/16 04:19:27 INFO : sub dir/hello world: Copied (new) 2025/04/16 04:19:27 DEBUG : Waiting for deletions to finish 2025/04/16 04:19:27 INFO : sub dir: Set directory modification time (using DirSetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-biqaqid5vuba'", Local "Local file system at /tmp/rclone2020710954", Modify Window "1ms" 2025/04/16 04:19:29 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestSyncNoTraverse (5.53s) === RUN TestCopyWithDepth run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-biqaqid5vuba'", Local "Local file system at /tmp/rclone2020710954", Modify Window "1ms" 2025/04/16 04:19:30 DEBUG : hello world2: Need to transfer - File not found at Destination 2025/04/16 04:19:30 DEBUG : Added delayed dir = "sub dir", newDst= 2025/04/16 04:19:30 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-biqaqid5vuba': Waiting for checks to finish 2025/04/16 04:19:30 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-biqaqid5vuba': Waiting for transfers to finish 2025/04/16 04:19:31 DEBUG : hello world2: md5 = 18801263db6dfe910e43eaf959ed8fb5 OK 2025/04/16 04:19:31 INFO : hello world2: Copied (new) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-biqaqid5vuba'", Local "Local file system at /tmp/rclone2020710954", Modify Window "1ms" --- PASS: TestCopyWithDepth (3.14s) === RUN TestCopyWithFilesFrom run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-biqaqid5vuba'", Local "Local file system at /tmp/rclone2020710954", Modify Window "1ms" 2025/04/16 04:19:33 DEBUG : potato2: Need to transfer - File not found at Destination 2025/04/16 04:19:33 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-biqaqid5vuba': Waiting for checks to finish 2025/04/16 04:19:33 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-biqaqid5vuba': Waiting for transfers to finish 2025/04/16 04:19:35 DEBUG : potato2: md5 = 8540367d7392744d9c15a8cc9bffc82f OK 2025/04/16 04:19:35 INFO : potato2: Copied (new) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-biqaqid5vuba'", Local "Local file system at /tmp/rclone2020710954", Modify Window "1ms" --- PASS: TestCopyWithFilesFrom (3.16s) === RUN TestCopyWithFilesFromAndNoTraverse run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-biqaqid5vuba'", Local "Local file system at /tmp/rclone2020710954", Modify Window "1ms" 2025/04/16 04:19:36 DEBUG : potato2: Need to transfer - File not found at Destination 2025/04/16 04:19:36 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-biqaqid5vuba': Waiting for checks to finish 2025/04/16 04:19:36 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-biqaqid5vuba': Waiting for transfers to finish 2025/04/16 04:19:38 DEBUG : potato2: md5 = c6b27694dea866d53e4be573862e3199 OK 2025/04/16 04:19:38 INFO : potato2: Copied (new) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-biqaqid5vuba'", Local "Local file system at /tmp/rclone2020710954", Modify Window "1ms" --- PASS: TestCopyWithFilesFromAndNoTraverse (3.25s) === RUN TestCopyEmptyDirectories run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-biqaqid5vuba'", Local "Local file system at /tmp/rclone2020710954", Modify Window "1ms" 2025/04/16 04:19:39 DEBUG : sub dir2/sub sub dir2: Making directory with metadata 2025/04/16 04:19:39 INFO : sub dir2/sub sub dir2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2025/04/16 04:19:39 INFO : sub dir2: Set directory modification time (using DirSetModTime) 2025/04/16 04:19:39 INFO : sub dir: Set directory modification time (using DirSetModTime) 2025/04/16 04:19:40 DEBUG : sub dir: Making directory with metadata 2025/04/16 04:19:41 INFO : sub dir: Made directory with metadata (mtime=2001-02-03T04:05:06.499999999Z) 2025/04/16 04:19:41 DEBUG : sub dir2: Making directory with metadata 2025/04/16 04:19:41 INFO : sub dir2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2025/04/16 04:19:41 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2025/04/16 04:19:41 DEBUG : sub dir2/sub sub dir2: Making directory with metadata 2025/04/16 04:19:42 INFO : sub dir2/sub sub dir2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2025/04/16 04:19:42 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-biqaqid5vuba': Waiting for checks to finish 2025/04/16 04:19:42 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-biqaqid5vuba': Waiting for transfers to finish 2025/04/16 04:19:43 DEBUG : sub dir/hello world: md5 = 863e2978da42bc8b40e81d761a8d24d9 OK 2025/04/16 04:19:43 INFO : sub dir/hello world: Copied (new) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-biqaqid5vuba'", Local "Local file system at /tmp/rclone2020710954", Modify Window "1ms" 2025/04/16 04:19:46 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc: Rmdir: contains trashed file: "cv6a9uf28ngrajena8kt5ijjn0" 2025/04/16 04:19:47 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestCopyEmptyDirectories (8.39s) === RUN TestCopyNoEmptyDirectories run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-biqaqid5vuba'", Local "Local file system at /tmp/rclone2020710954", Modify Window "1ms" 2025/04/16 04:19:48 INFO : sub dir2: Making directory 2025/04/16 04:19:48 DEBUG : sub dir2/sub sub dir2: Making directory with metadata 2025/04/16 04:19:48 INFO : sub dir2/sub sub dir2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2025/04/16 04:19:48 DEBUG : Added delayed dir = "sub dir", newDst= 2025/04/16 04:19:48 DEBUG : Added delayed dir = "sub dir2", newDst= 2025/04/16 04:19:48 DEBUG : Added delayed dir = "sub dir2/sub sub dir2", newDst= 2025/04/16 04:19:48 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2025/04/16 04:19:48 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-biqaqid5vuba': Waiting for checks to finish 2025/04/16 04:19:48 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-biqaqid5vuba': Waiting for transfers to finish 2025/04/16 04:19:50 DEBUG : sub dir/hello world: md5 = cb55f761ac7bb8e5fe37167a87277084 OK 2025/04/16 04:19:50 INFO : sub dir/hello world: Copied (new) 2025/04/16 04:19:51 INFO : sub dir: Set directory modification time (using DirSetModTime) 2025/04/16 04:19:53 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestCopyNoEmptyDirectories (5.41s) === RUN TestMoveEmptyDirectories run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-biqaqid5vuba'", Local "Local file system at /tmp/rclone2020710954", Modify Window "1ms" 2025/04/16 04:19:53 DEBUG : sub dir2: Making directory with metadata 2025/04/16 04:19:53 INFO : sub dir2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2025/04/16 04:19:53 DEBUG : sub dir: Making directory with metadata 2025/04/16 04:19:54 INFO : sub dir: Made directory with metadata (mtime=2025-04-16T04:19:53.776468441Z) 2025/04/16 04:19:54 DEBUG : sub dir2: Making directory with metadata 2025/04/16 04:19:55 INFO : sub dir2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2025/04/16 04:19:55 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2025/04/16 04:19:55 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-biqaqid5vuba': Waiting for checks to finish 2025/04/16 04:19:55 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-biqaqid5vuba': Waiting for transfers to finish 2025/04/16 04:19:56 DEBUG : sub dir/hello world: md5 = 7921ef46f4a033113194280f99b5836d OK 2025/04/16 04:19:56 INFO : sub dir/hello world: Copied (new) 2025/04/16 04:19:56 INFO : sub dir/hello world: Deleted run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-biqaqid5vuba'", Local "Local file system at /tmp/rclone2020710954", Modify Window "1ms" 2025/04/16 04:19:59 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestMoveEmptyDirectories (7.10s) === RUN TestSyncNoUpdateDirModtime run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-biqaqid5vuba'", Local "Local file system at /tmp/rclone2020710954", Modify Window "1ms" 2025/04/16 04:20:00 DEBUG : sub dir no update dir modtime: Making directory with metadata 2025/04/16 04:20:00 INFO : sub dir no update dir modtime: Made directory with metadata (mtime=2001-02-03T04:05:06.499999999Z) 2025/04/16 04:20:02 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-biqaqid5vuba': Waiting for checks to finish 2025/04/16 04:20:02 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-biqaqid5vuba': Waiting for transfers to finish 2025/04/16 04:20:02 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-biqaqid5vuba'", Local "Local file system at /tmp/rclone2020710954", Modify Window "1ms" --- PASS: TestSyncNoUpdateDirModtime (4.12s) === RUN TestMoveNoEmptyDirectories run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-biqaqid5vuba'", Local "Local file system at /tmp/rclone2020710954", Modify Window "1ms" 2025/04/16 04:20:05 INFO : sub dir2: Making directory 2025/04/16 04:20:05 DEBUG : Added delayed dir = "sub dir", newDst= 2025/04/16 04:20:05 DEBUG : Added delayed dir = "sub dir2", newDst= 2025/04/16 04:20:05 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2025/04/16 04:20:05 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-biqaqid5vuba': Waiting for checks to finish 2025/04/16 04:20:05 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-biqaqid5vuba': Waiting for transfers to finish 2025/04/16 04:20:07 DEBUG : sub dir/hello world: md5 = 687981351707c0a6056d5a2acca8ce97 OK 2025/04/16 04:20:07 INFO : sub dir/hello world: Copied (new) 2025/04/16 04:20:07 INFO : sub dir/hello world: Deleted 2025/04/16 04:20:07 INFO : sub dir: Set directory modification time (using DirSetModTime) 2025/04/16 04:20:09 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestMoveNoEmptyDirectories (4.99s) === RUN TestSyncEmptyDirectories run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-biqaqid5vuba'", Local "Local file system at /tmp/rclone2020710954", Modify Window "1ms" 2025/04/16 04:20:09 DEBUG : sub dir2: Making directory with metadata 2025/04/16 04:20:09 INFO : sub dir2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2025/04/16 04:20:09 INFO : sub dir: Set directory modification time (using DirSetModTime) 2025/04/16 04:20:10 DEBUG : sub dir: Making directory with metadata 2025/04/16 04:20:10 INFO : sub dir: Made directory with metadata (mtime=2001-02-03T04:05:06.499999999Z) 2025/04/16 04:20:10 DEBUG : sub dir2: Making directory with metadata 2025/04/16 04:20:11 INFO : sub dir2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2025/04/16 04:20:11 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2025/04/16 04:20:11 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-biqaqid5vuba': Waiting for checks to finish 2025/04/16 04:20:11 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-biqaqid5vuba': Waiting for transfers to finish 2025/04/16 04:20:13 DEBUG : sub dir/hello world: md5 = 3ec9d52703485f6d14437ba784c6c26f OK 2025/04/16 04:20:13 INFO : sub dir/hello world: Copied (new) 2025/04/16 04:20:13 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-biqaqid5vuba'", Local "Local file system at /tmp/rclone2020710954", Modify Window "1ms" 2025/04/16 04:20:16 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestSyncEmptyDirectories (7.26s) === RUN TestSyncSetDelayedModTimes run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-biqaqid5vuba'", Local "Local file system at /tmp/rclone2020710954", Modify Window "1ms" sync_test.go:507: Backend doesn't have DirModTimeUpdatesOnWrite set --- SKIP: TestSyncSetDelayedModTimes (0.43s) === RUN TestSyncNoEmptyDirectories run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-biqaqid5vuba'", Local "Local file system at /tmp/rclone2020710954", Modify Window "1ms" 2025/04/16 04:20:17 INFO : sub dir2: Making directory 2025/04/16 04:20:17 DEBUG : Added delayed dir = "sub dir", newDst= 2025/04/16 04:20:17 DEBUG : Added delayed dir = "sub dir2", newDst= 2025/04/16 04:20:17 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2025/04/16 04:20:17 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-biqaqid5vuba': Waiting for checks to finish 2025/04/16 04:20:17 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-biqaqid5vuba': Waiting for transfers to finish 2025/04/16 04:20:19 DEBUG : sub dir/hello world: md5 = f7ffd27a0a27979ff4a4249299f71812 OK 2025/04/16 04:20:19 INFO : sub dir/hello world: Copied (new) 2025/04/16 04:20:19 DEBUG : Waiting for deletions to finish 2025/04/16 04:20:20 INFO : sub dir: Set directory modification time (using DirSetModTime) 2025/04/16 04:20:22 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestSyncNoEmptyDirectories (5.13s) === RUN TestServerSideCopy run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-biqaqid5vuba'", Local "Local file system at /tmp/rclone2020710954", Modify Window "1ms" 2025/04/16 04:20:24 DEBUG : sub dir/hello world: md5 = 636a54704b56e6c57d88a543cbfa0040 OK 2025/04/16 04:20:25 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-qanelek2mewi" 2025/04/16 04:20:25 DEBUG : Creating backend with remote "TestDrive:crypt/siu1102cdordskb24mns87r4j1d7fcfdq56gdnkm872sdhe28on0" sync_test.go:590: Server side copy (if possible) Encrypted drive 'TestCryptDrive:rclone-test-biqaqid5vuba' -> Encrypted drive 'TestCryptDrive:rclone-test-qanelek2mewi' 2025/04/16 04:20:26 DEBUG : Added delayed dir = "sub dir", newDst= 2025/04/16 04:20:26 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2025/04/16 04:20:26 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-qanelek2mewi': Waiting for checks to finish 2025/04/16 04:20:26 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-qanelek2mewi': Waiting for transfers to finish 2025/04/16 04:20:29 INFO : sub dir/hello world: Copied (server-side copy) 2025/04/16 04:20:29 INFO : sub dir: Set directory modification time (using DirSetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-biqaqid5vuba'", Local "Local file system at /tmp/rclone2020710954", Modify Window "1ms" 2025/04/16 04:20:30 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-qanelek2mewi': Purge remote 2025/04/16 04:20:31 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestServerSideCopy (10.22s) === RUN TestCopyOverSelf run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-biqaqid5vuba'", Local "Local file system at /tmp/rclone2020710954", Modify Window "1ms" 2025/04/16 04:20:35 DEBUG : sub dir/hello world: md5 = 68b16d9c57036df23cd3f3d64dcf65bd OK 2025/04/16 04:20:36 INFO : sub dir: Set directory modification time (using SetModTime) 2025/04/16 04:20:36 DEBUG : Added delayed dir = "sub dir", newDst=sub dir 2025/04/16 04:20:36 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-biqaqid5vuba': Waiting for checks to finish 2025/04/16 04:20:36 DEBUG : sub dir/hello world: Sizes differ (src 17 vs dst 11) 2025/04/16 04:20:36 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-biqaqid5vuba': Waiting for transfers to finish 2025/04/16 04:20:37 DEBUG : sub dir/hello world: md5 = 0cdedd5ab4731be3219761f245d32918 OK 2025/04/16 04:20:37 INFO : sub dir/hello world: Copied (replaced existing) 2025/04/16 04:20:38 INFO : sub dir: Set directory modification time (using SetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-biqaqid5vuba'", Local "Local file system at /tmp/rclone2020710954", Modify Window "1ms" 2025/04/16 04:20:39 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestCopyOverSelf (8.05s) === RUN TestServerSideCopyOverSelf run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-biqaqid5vuba'", Local "Local file system at /tmp/rclone2020710954", Modify Window "1ms" 2025/04/16 04:20:43 DEBUG : sub dir/hello world: md5 = 2dd9f7b507d5b5a1bceded8b95282148 OK 2025/04/16 04:20:43 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-wimidex1koba" 2025/04/16 04:20:43 DEBUG : Creating backend with remote "TestDrive:crypt/9u4u3eqm0l8dd928rllnvui09p34it1savlo71rcj23n092os7tg" sync_test.go:626: Server side copy (if possible) Encrypted drive 'TestCryptDrive:rclone-test-biqaqid5vuba' -> Encrypted drive 'TestCryptDrive:rclone-test-wimidex1koba' 2025/04/16 04:20:45 DEBUG : Added delayed dir = "sub dir", newDst= 2025/04/16 04:20:45 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2025/04/16 04:20:45 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wimidex1koba': Waiting for checks to finish 2025/04/16 04:20:45 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wimidex1koba': Waiting for transfers to finish 2025/04/16 04:20:47 INFO : sub dir/hello world: Copied (server-side copy) 2025/04/16 04:20:48 INFO : sub dir: Set directory modification time (using DirSetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-biqaqid5vuba'", Local "Local file system at /tmp/rclone2020710954", Modify Window "1ms" 2025/04/16 04:20:49 DEBUG : sub dir/hello world: md5 = 710170357aead7dfd269bf551b8fc2c6 OK 2025/04/16 04:20:50 DEBUG : sub dir: Directory modification time the same (differ by 0s, within tolerance 1ms) 2025/04/16 04:20:50 DEBUG : Added delayed dir = "sub dir", newDst=sub dir 2025/04/16 04:20:50 DEBUG : sub dir/hello world: Sizes differ (src 17 vs dst 11) 2025/04/16 04:20:50 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wimidex1koba': Waiting for checks to finish 2025/04/16 04:20:50 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wimidex1koba': Waiting for transfers to finish 2025/04/16 04:20:52 INFO : sub dir/hello world: Copied (server-side copy) 2025/04/16 04:20:52 INFO : sub dir: Set directory modification time (using SetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-biqaqid5vuba'", Local "Local file system at /tmp/rclone2020710954", Modify Window "1ms" 2025/04/16 04:20:53 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wimidex1koba': Purge remote 2025/04/16 04:20:54 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestServerSideCopyOverSelf (15.51s) === RUN TestMoveOverSelf run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-biqaqid5vuba'", Local "Local file system at /tmp/rclone2020710954", Modify Window "1ms" 2025/04/16 04:20:58 DEBUG : sub dir/hello world: md5 = 22f67a6131f5bd4039e71b9859eb8e21 OK 2025/04/16 04:21:00 INFO : sub dir: Set directory modification time (using SetModTime) 2025/04/16 04:21:00 DEBUG : Added delayed dir = "sub dir", newDst=sub dir 2025/04/16 04:21:00 DEBUG : sub dir/hello world: Sizes differ (src 17 vs dst 11) 2025/04/16 04:21:00 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-biqaqid5vuba': Waiting for checks to finish 2025/04/16 04:21:00 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-biqaqid5vuba': Waiting for transfers to finish 2025/04/16 04:21:01 DEBUG : sub dir/hello world: md5 = 5cb96079ac996268fa4b7ce3a51dfee3 OK 2025/04/16 04:21:01 INFO : sub dir/hello world: Copied (replaced existing) 2025/04/16 04:21:01 INFO : sub dir/hello world: Deleted 2025/04/16 04:21:01 INFO : sub dir: Set directory modification time (using SetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-biqaqid5vuba'", Local "Local file system at /tmp/rclone2020710954", Modify Window "1ms" 2025/04/16 04:21:03 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestMoveOverSelf (8.23s) === RUN TestServerSideMoveOverSelf run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-biqaqid5vuba'", Local "Local file system at /tmp/rclone2020710954", Modify Window "1ms" 2025/04/16 04:21:06 DEBUG : sub dir/hello world: md5 = 6bcb6244b608d1dd1006ba0d50703532 OK 2025/04/16 04:21:07 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-xexonuc9nigi" 2025/04/16 04:21:07 DEBUG : Creating backend with remote "TestDrive:crypt/ocjcoh41db8nlvsopevje0183vqk6cc2bmvklkiqgtibie236g30" sync_test.go:671: Server side copy (if possible) Encrypted drive 'TestCryptDrive:rclone-test-biqaqid5vuba' -> Encrypted drive 'TestCryptDrive:rclone-test-xexonuc9nigi' 2025/04/16 04:21:08 DEBUG : Added delayed dir = "sub dir", newDst= 2025/04/16 04:21:08 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2025/04/16 04:21:08 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-xexonuc9nigi': Waiting for checks to finish 2025/04/16 04:21:08 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-xexonuc9nigi': Waiting for transfers to finish 2025/04/16 04:21:11 INFO : sub dir/hello world: Copied (server-side copy) 2025/04/16 04:21:11 INFO : sub dir: Set directory modification time (using DirSetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-biqaqid5vuba'", Local "Local file system at /tmp/rclone2020710954", Modify Window "1ms" 2025/04/16 04:21:13 DEBUG : sub dir/hello world: md5 = a41de412fa179014b26c6ffd46a3f983 OK 2025/04/16 04:21:14 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-xexonuc9nigi': Using server-side directory move 2025/04/16 04:21:14 INFO : Encrypted drive 'TestCryptDrive:rclone-test-xexonuc9nigi': Server side directory move failed - fallback to file moves: can't copy directory - destination already exists 2025/04/16 04:21:14 DEBUG : sub dir: Directory modification time the same (differ by 0s, within tolerance 1ms) 2025/04/16 04:21:14 DEBUG : Added delayed dir = "sub dir", newDst=sub dir 2025/04/16 04:21:14 DEBUG : sub dir/hello world: Sizes differ (src 17 vs dst 11) 2025/04/16 04:21:14 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-xexonuc9nigi': Waiting for checks to finish 2025/04/16 04:21:14 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-xexonuc9nigi': Waiting for transfers to finish 2025/04/16 04:21:15 INFO : sub dir/hello world: Deleted 2025/04/16 04:21:15 INFO : sub dir/hello world: Moved (server-side) 2025/04/16 04:21:16 INFO : sub dir: Set directory modification time (using SetModTime) 2025/04/16 04:21:18 DEBUG : sub dir/hello world: md5 = c0ba5a3b16f6573ce750d3010df548f7 OK 2025/04/16 04:21:19 DEBUG : testing file moves 2025/04/16 04:21:19 DEBUG : sub dir: Directory modification time the same (differ by 0s, within tolerance 1ms) 2025/04/16 04:21:19 DEBUG : Added delayed dir = "sub dir", newDst=sub dir 2025/04/16 04:21:19 DEBUG : sub dir/hello world: Sizes differ (src 24 vs dst 17) 2025/04/16 04:21:19 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-xexonuc9nigi': Waiting for checks to finish 2025/04/16 04:21:19 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-xexonuc9nigi': Waiting for transfers to finish 2025/04/16 04:21:19 INFO : sub dir/hello world: Deleted 2025/04/16 04:21:20 INFO : sub dir/hello world: Moved (server-side) 2025/04/16 04:21:20 INFO : sub dir: Set directory modification time (using SetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-biqaqid5vuba'", Local "Local file system at /tmp/rclone2020710954", Modify Window "1ms" 2025/04/16 04:21:21 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-xexonuc9nigi': Purge remote --- PASS: TestServerSideMoveOverSelf (20.54s) === RUN TestCopyAfterDelete run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-biqaqid5vuba'", Local "Local file system at /tmp/rclone2020710954", Modify Window "1ms" 2025/04/16 04:21:27 DEBUG : sub dir/hello world: md5 = d6ba0526c69c481a79e9a3d80ce5487f OK 2025/04/16 04:21:27 ERROR : : error listing: directory not found 2025/04/16 04:21:27 INFO : Local file system at /tmp/rclone2020710954: Making directory 2025/04/16 04:21:28 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-biqaqid5vuba': Waiting for checks to finish 2025/04/16 04:21:28 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-biqaqid5vuba': Waiting for transfers to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-biqaqid5vuba'", Local "Local file system at /tmp/rclone2020710954", Modify Window "1ms" 2025/04/16 04:21:30 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestCopyAfterDelete (6.03s) === RUN TestCopyRedownload run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-biqaqid5vuba'", Local "Local file system at /tmp/rclone2020710954", Modify Window "1ms" 2025/04/16 04:21:33 DEBUG : sub dir/hello world: md5 = 94310eb31f876dc5d89432146e0dc7c3 OK 2025/04/16 04:21:34 DEBUG : Added delayed dir = "sub dir", newDst= 2025/04/16 04:21:34 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2025/04/16 04:21:34 DEBUG : Local file system at /tmp/rclone2020710954: Waiting for checks to finish 2025/04/16 04:21:34 DEBUG : Local file system at /tmp/rclone2020710954: Waiting for transfers to finish 2025/04/16 04:21:35 DEBUG : sub dir/hello world.285f0a30.partial: renamed to: sub dir/hello world 2025/04/16 04:21:35 INFO : sub dir/hello world: Copied (new) 2025/04/16 04:21:35 INFO : sub dir: Set directory modification time (using DirSetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-biqaqid5vuba'", Local "Local file system at /tmp/rclone2020710954", Modify Window "1ms" 2025/04/16 04:21:36 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestCopyRedownload (6.36s) === RUN TestSyncBasedOnCheckSum run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-biqaqid5vuba'", Local "Local file system at /tmp/rclone2020710954", Modify Window "1ms" 2025/04/16 04:21:37 DEBUG : check sum: Need to transfer - File not found at Destination 2025/04/16 04:21:37 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-biqaqid5vuba': Waiting for checks to finish 2025/04/16 04:21:37 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-biqaqid5vuba': Waiting for transfers to finish 2025/04/16 04:21:39 DEBUG : check sum: md5 = 7392f7efbf025907be783d6f4e288ffb OK 2025/04/16 04:21:39 INFO : check sum: Copied (new) 2025/04/16 04:21:39 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-biqaqid5vuba'", Local "Local file system at /tmp/rclone2020710954", Modify Window "1ms" 2025/04/16 04:21:39 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-biqaqid5vuba': Waiting for checks to finish 2025/04/16 04:21:39 NOTICE: Encrypted drive 'TestCryptDrive:rclone-test-biqaqid5vuba': --checksum is in use but the source and destination have no hashes in common; falling back to --size-only 2025/04/16 04:21:39 DEBUG : check sum: Size of src and dst objects identical 2025/04/16 04:21:39 DEBUG : check sum: Unchanged skipping 2025/04/16 04:21:39 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-biqaqid5vuba': Waiting for transfers to finish 2025/04/16 04:21:39 DEBUG : Waiting for deletions to finish 2025/04/16 04:21:39 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-biqaqid5vuba'", Local "Local file system at /tmp/rclone2020710954", Modify Window "1ms" --- PASS: TestSyncBasedOnCheckSum (4.29s) === RUN TestSyncSizeOnly run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-biqaqid5vuba'", Local "Local file system at /tmp/rclone2020710954", Modify Window "1ms" 2025/04/16 04:21:42 DEBUG : sizeonly: Need to transfer - File not found at Destination 2025/04/16 04:21:42 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-biqaqid5vuba': Waiting for checks to finish 2025/04/16 04:21:42 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-biqaqid5vuba': Waiting for transfers to finish 2025/04/16 04:21:43 DEBUG : sizeonly: md5 = 4eeb2ce06d482cfa341c1e9b3184601a OK 2025/04/16 04:21:43 INFO : sizeonly: Copied (new) 2025/04/16 04:21:43 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-biqaqid5vuba'", Local "Local file system at /tmp/rclone2020710954", Modify Window "1ms" 2025/04/16 04:21:44 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-biqaqid5vuba': Waiting for checks to finish 2025/04/16 04:21:44 DEBUG : sizeonly: Sizes identical 2025/04/16 04:21:44 DEBUG : sizeonly: Unchanged skipping 2025/04/16 04:21:44 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-biqaqid5vuba': Waiting for transfers to finish 2025/04/16 04:21:44 DEBUG : Waiting for deletions to finish 2025/04/16 04:21:44 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-biqaqid5vuba'", Local "Local file system at /tmp/rclone2020710954", Modify Window "1ms" --- PASS: TestSyncSizeOnly (4.19s) === RUN TestSyncIgnoreSize run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-biqaqid5vuba'", Local "Local file system at /tmp/rclone2020710954", Modify Window "1ms" 2025/04/16 04:21:46 DEBUG : ignore-size: Need to transfer - File not found at Destination 2025/04/16 04:21:46 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-biqaqid5vuba': Waiting for checks to finish 2025/04/16 04:21:46 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-biqaqid5vuba': Waiting for transfers to finish 2025/04/16 04:21:47 DEBUG : ignore-size: md5 = f657df54ff8873429fba456702253e50 OK 2025/04/16 04:21:47 INFO : ignore-size: Copied (new) 2025/04/16 04:21:47 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-biqaqid5vuba'", Local "Local file system at /tmp/rclone2020710954", Modify Window "1ms" 2025/04/16 04:21:48 DEBUG : ignore-size: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/16 04:21:48 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-biqaqid5vuba': Waiting for checks to finish 2025/04/16 04:21:48 DEBUG : ignore-size: Unchanged skipping 2025/04/16 04:21:48 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-biqaqid5vuba': Waiting for transfers to finish 2025/04/16 04:21:48 DEBUG : Waiting for deletions to finish 2025/04/16 04:21:48 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-biqaqid5vuba'", Local "Local file system at /tmp/rclone2020710954", Modify Window "1ms" --- PASS: TestSyncIgnoreSize (4.13s) === RUN TestSyncIgnoreTimes run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-biqaqid5vuba'", Local "Local file system at /tmp/rclone2020710954", Modify Window "1ms" 2025/04/16 04:21:51 DEBUG : existing: md5 = 1768a9a999de859bb548793cf2e22e98 OK 2025/04/16 04:21:52 DEBUG : existing: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/16 04:21:52 DEBUG : existing: Unchanged skipping 2025/04/16 04:21:52 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-biqaqid5vuba': Waiting for checks to finish 2025/04/16 04:21:52 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-biqaqid5vuba': Waiting for transfers to finish 2025/04/16 04:21:52 DEBUG : Waiting for deletions to finish 2025/04/16 04:21:52 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-biqaqid5vuba'", Local "Local file system at /tmp/rclone2020710954", Modify Window "1ms" 2025/04/16 04:21:52 DEBUG : existing: Transferring unconditionally as --ignore-times is in use 2025/04/16 04:21:52 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-biqaqid5vuba': Waiting for checks to finish 2025/04/16 04:21:52 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-biqaqid5vuba': Waiting for transfers to finish 2025/04/16 04:21:53 DEBUG : existing: md5 = d223af78c4009c991d39993aad77b42c OK 2025/04/16 04:21:53 INFO : existing: Copied (replaced existing) 2025/04/16 04:21:53 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-biqaqid5vuba'", Local "Local file system at /tmp/rclone2020710954", Modify Window "1ms" --- PASS: TestSyncIgnoreTimes (5.52s) === RUN TestSyncIgnoreExisting run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-biqaqid5vuba'", Local "Local file system at /tmp/rclone2020710954", Modify Window "1ms" 2025/04/16 04:21:56 DEBUG : existing: Need to transfer - File not found at Destination 2025/04/16 04:21:56 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-biqaqid5vuba': Waiting for checks to finish 2025/04/16 04:21:56 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-biqaqid5vuba': Waiting for transfers to finish 2025/04/16 04:21:57 DEBUG : existing: md5 = b51ea15384c5f870316a0fdd980e09d6 OK 2025/04/16 04:21:57 INFO : existing: Copied (new) 2025/04/16 04:21:57 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-biqaqid5vuba'", Local "Local file system at /tmp/rclone2020710954", Modify Window "1ms" 2025/04/16 04:21:57 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-biqaqid5vuba': Waiting for checks to finish 2025/04/16 04:21:57 DEBUG : existing: Destination exists, skipping 2025/04/16 04:21:57 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-biqaqid5vuba': Waiting for transfers to finish 2025/04/16 04:21:57 DEBUG : Waiting for deletions to finish 2025/04/16 04:21:57 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-biqaqid5vuba'", Local "Local file system at /tmp/rclone2020710954", Modify Window "1ms" --- PASS: TestSyncIgnoreExisting (4.09s) === RUN TestSyncIgnoreErrors run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-biqaqid5vuba'", Local "Local file system at /tmp/rclone2020710954", Modify Window "1ms" 2025/04/16 04:22:02 DEBUG : b/potato: md5 = 735efcd3cd8d3438602ff401739754cf OK 2025/04/16 04:22:04 DEBUG : c/non empty space: md5 = f01286af652057dc64eb5082cd93a940 OK 2025/04/16 04:22:04 INFO : d: Making directory 2025/04/16 04:22:05 DEBUG : Added delayed dir = "a", newDst= 2025/04/16 04:22:06 INFO : c: Set directory modification time (using SetModTime) 2025/04/16 04:22:06 DEBUG : Added delayed dir = "c", newDst=c 2025/04/16 04:22:06 DEBUG : c/non empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/04/16 04:22:06 DEBUG : a/potato2: Need to transfer - File not found at Destination 2025/04/16 04:22:06 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-biqaqid5vuba': Waiting for checks to finish 2025/04/16 04:22:06 DEBUG : c/non empty space: Unchanged skipping 2025/04/16 04:22:06 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-biqaqid5vuba': Waiting for transfers to finish 2025/04/16 04:22:08 DEBUG : a/potato2: md5 = 431f408c3abc78e4e70aa370409b7291 OK 2025/04/16 04:22:08 INFO : a/potato2: Copied (new) 2025/04/16 04:22:08 DEBUG : Waiting for deletions to finish 2025/04/16 04:22:09 INFO : b/potato: Deleted 2025/04/16 04:22:09 INFO : a: Set directory modification time (using DirSetModTime) 2025/04/16 04:22:09 INFO : d: Removing directory 2025/04/16 04:22:10 INFO : b: Removing directory 2025/04/16 04:22:10 DEBUG : 32d8ua6196mc1r7qkfog53rkg0: Rmdir: contains trashed file: "2m507n64kafsi59v9q71r281a4" 2025/04/16 04:22:10 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-biqaqid5vuba': deleted 2 directories run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-biqaqid5vuba'", Local "Local file system at /tmp/rclone2020710954", Modify Window "1ms" 2025/04/16 04:22:13 DEBUG : 3i9du405pfogq3ncai6pg7ouio: Rmdir: contains trashed file: "982d3pss7t5pn0il16r2foj31s" 2025/04/16 04:22:14 DEBUG : 2bsvlrk2ne1lfitm6tttcu0qt8: Rmdir: contains trashed file: "89l8renevh3mji1c8r1p7qn6tg" --- PASS: TestSyncIgnoreErrors (15.72s) === RUN TestSyncAfterChangingModtimeOnly run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-biqaqid5vuba'", Local "Local file system at /tmp/rclone2020710954", Modify Window "1ms" 2025/04/16 04:22:17 DEBUG : empty space: md5 = 830e0111379af5083c6c1365c087e65b OK 2025/04/16 04:22:17 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-biqaqid5vuba': Waiting for checks to finish 2025/04/16 04:22:17 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/16 04:22:17 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-biqaqid5vuba': Waiting for transfers to finish 2025/04/16 04:22:17 NOTICE: empty space: Skipped copy as --dry-run is set (size 1) 2025/04/16 04:22:17 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-biqaqid5vuba'", Local "Local file system at /tmp/rclone2020710954", Modify Window "1ms" 2025/04/16 04:22:17 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/16 04:22:17 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-biqaqid5vuba': Waiting for checks to finish 2025/04/16 04:22:17 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-biqaqid5vuba': Waiting for transfers to finish 2025/04/16 04:22:19 DEBUG : empty space: md5 = d816928e5e1ecfe912b21f0032f5e46a OK 2025/04/16 04:22:19 INFO : empty space: Copied (replaced existing) 2025/04/16 04:22:19 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-biqaqid5vuba'", Local "Local file system at /tmp/rclone2020710954", Modify Window "1ms" --- PASS: TestSyncAfterChangingModtimeOnly (5.67s) === RUN TestSyncAfterChangingModtimeOnlyWithNoUpdateModTime run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-biqaqid5vuba'", Local "Local file system at /tmp/rclone2020710954", Modify Window "1ms" sync_test.go:1016: Can't check this if no hashes supported --- PASS: TestSyncAfterChangingModtimeOnlyWithNoUpdateModTime (0.41s) === RUN TestSyncDoesntUpdateModtime run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-biqaqid5vuba'", Local "Local file system at /tmp/rclone2020710954", Modify Window "1ms" 2025/04/16 04:22:23 DEBUG : foo: md5 = cc6ae9d906fdc92de2f9f82268e3c87f OK 2025/04/16 04:22:23 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-biqaqid5vuba': Waiting for checks to finish 2025/04/16 04:22:23 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/16 04:22:23 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-biqaqid5vuba': Waiting for transfers to finish 2025/04/16 04:22:25 DEBUG : foo: md5 = 26789ba74e4704313100699155125956 OK 2025/04/16 04:22:25 INFO : foo: Copied (replaced existing) 2025/04/16 04:22:25 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-biqaqid5vuba'", Local "Local file system at /tmp/rclone2020710954", Modify Window "1ms" --- PASS: TestSyncDoesntUpdateModtime (4.91s) === RUN TestSyncAfterAddingAFile run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-biqaqid5vuba'", Local "Local file system at /tmp/rclone2020710954", Modify Window "1ms" 2025/04/16 04:22:28 DEBUG : empty space: md5 = 6dc5d09b606f0f12432600892f5a39e6 OK 2025/04/16 04:22:28 DEBUG : empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/04/16 04:22:28 DEBUG : potato: Need to transfer - File not found at Destination 2025/04/16 04:22:28 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-biqaqid5vuba': Waiting for checks to finish 2025/04/16 04:22:28 DEBUG : empty space: Unchanged skipping 2025/04/16 04:22:28 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-biqaqid5vuba': Waiting for transfers to finish 2025/04/16 04:22:29 DEBUG : potato: md5 = caffbd74cc78f4632de2dfb8c1596363 OK 2025/04/16 04:22:29 INFO : potato: Copied (new) 2025/04/16 04:22:29 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-biqaqid5vuba'", Local "Local file system at /tmp/rclone2020710954", Modify Window "1ms" --- PASS: TestSyncAfterAddingAFile (5.22s) === RUN TestSyncAfterChangingFilesSizeOnly run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-biqaqid5vuba'", Local "Local file system at /tmp/rclone2020710954", Modify Window "1ms" 2025/04/16 04:22:33 DEBUG : potato: md5 = 2be8225e3a70a603398ad48c78ebc38b OK 2025/04/16 04:22:33 DEBUG : potato: Sizes differ (src 21 vs dst 60) 2025/04/16 04:22:33 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-biqaqid5vuba': Waiting for checks to finish 2025/04/16 04:22:33 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-biqaqid5vuba': Waiting for transfers to finish 2025/04/16 04:22:34 DEBUG : potato: md5 = c3fef5bee7c7d7ac9f5b36816901b864 OK 2025/04/16 04:22:34 INFO : potato: Copied (replaced existing) 2025/04/16 04:22:34 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-biqaqid5vuba'", Local "Local file system at /tmp/rclone2020710954", Modify Window "1ms" --- PASS: TestSyncAfterChangingFilesSizeOnly (4.41s) === RUN TestSyncAfterChangingContentsOnly run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-biqaqid5vuba'", Local "Local file system at /tmp/rclone2020710954", Modify Window "1ms" 2025/04/16 04:22:37 DEBUG : potato: md5 = 39199f041dbc1d134739887821c94cb5 OK 2025/04/16 04:22:38 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-biqaqid5vuba': Waiting for checks to finish 2025/04/16 04:22:38 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/16 04:22:38 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-biqaqid5vuba': Waiting for transfers to finish 2025/04/16 04:22:39 DEBUG : potato: md5 = 7ad75c35153158be1c419898e07d468c OK 2025/04/16 04:22:39 INFO : potato: Copied (replaced existing) 2025/04/16 04:22:39 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-biqaqid5vuba'", Local "Local file system at /tmp/rclone2020710954", Modify Window "1ms" --- PASS: TestSyncAfterChangingContentsOnly (4.52s) === RUN TestSyncAfterRemovingAFileAndAddingAFileDryRun run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-biqaqid5vuba'", Local "Local file system at /tmp/rclone2020710954", Modify Window "1ms" 2025/04/16 04:22:42 DEBUG : potato: md5 = 3b14bc0577a127aee4e1d5eac1800762 OK 2025/04/16 04:22:43 DEBUG : empty space: md5 = 3dbe0cf81d5cb0fe0ed91e85ac36e99f OK 2025/04/16 04:22:43 DEBUG : potato2: Need to transfer - File not found at Destination 2025/04/16 04:22:43 DEBUG : empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/04/16 04:22:43 DEBUG : empty space: Unchanged skipping 2025/04/16 04:22:43 NOTICE: potato2: Skipped copy as --dry-run is set (size 60) 2025/04/16 04:22:43 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-biqaqid5vuba': Waiting for checks to finish 2025/04/16 04:22:43 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-biqaqid5vuba': Waiting for transfers to finish 2025/04/16 04:22:43 DEBUG : Waiting for deletions to finish 2025/04/16 04:22:43 NOTICE: potato: Skipped delete as --dry-run is set (size 21) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-biqaqid5vuba'", Local "Local file system at /tmp/rclone2020710954", Modify Window "1ms" --- PASS: TestSyncAfterRemovingAFileAndAddingAFileDryRun (4.91s) === RUN TestSyncAfterRemovingAFileAndAddingAFile run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-biqaqid5vuba'", Local "Local file system at /tmp/rclone2020710954", Modify Window "1ms" 2025/04/16 04:22:47 DEBUG : potato: md5 = 92d216fadacd5095c5e16927b25ed6d4 OK 2025/04/16 04:22:48 DEBUG : empty space: md5 = d224306f6017aa304600bbe4dc12260d OK 2025/04/16 04:22:48 DEBUG : empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/04/16 04:22:48 DEBUG : potato2: Need to transfer - File not found at Destination 2025/04/16 04:22:48 DEBUG : empty space: Unchanged skipping 2025/04/16 04:22:48 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-biqaqid5vuba': Waiting for checks to finish 2025/04/16 04:22:48 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-biqaqid5vuba': Waiting for transfers to finish 2025/04/16 04:22:50 DEBUG : potato2: md5 = af1b8f593690e9c361efa0c11b2941fc OK 2025/04/16 04:22:50 INFO : potato2: Copied (new) 2025/04/16 04:22:50 DEBUG : Waiting for deletions to finish 2025/04/16 04:22:50 INFO : potato: Deleted run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-biqaqid5vuba'", Local "Local file system at /tmp/rclone2020710954", Modify Window "1ms" --- PASS: TestSyncAfterRemovingAFileAndAddingAFile (6.98s) === RUN TestSyncAfterRemovingAFileAndAddingAFileSubDir run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-biqaqid5vuba'", Local "Local file system at /tmp/rclone2020710954", Modify Window "1ms" 2025/04/16 04:22:54 DEBUG : b/potato: md5 = ba763900055261a392c70ee9cf0cb503 OK 2025/04/16 04:22:56 DEBUG : c/non empty space: md5 = c3b06504164ac96d2a885f31fb49784d OK 2025/04/16 04:22:56 INFO : d: Making directory 2025/04/16 04:22:57 INFO : d/e: Making directory 2025/04/16 04:22:59 DEBUG : Added delayed dir = "a", newDst= 2025/04/16 04:23:00 INFO : c: Set directory modification time (using SetModTime) 2025/04/16 04:23:00 DEBUG : Added delayed dir = "c", newDst=c 2025/04/16 04:23:00 DEBUG : c/non empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/04/16 04:23:00 DEBUG : c/non empty space: Unchanged skipping 2025/04/16 04:23:00 DEBUG : a/potato2: Need to transfer - File not found at Destination 2025/04/16 04:23:00 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-biqaqid5vuba': Waiting for checks to finish 2025/04/16 04:23:00 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-biqaqid5vuba': Waiting for transfers to finish 2025/04/16 04:23:02 DEBUG : a/potato2: md5 = 5fc4f527b97ee93a8f4dc8cc609b048d OK 2025/04/16 04:23:02 INFO : a/potato2: Copied (new) 2025/04/16 04:23:02 DEBUG : Waiting for deletions to finish 2025/04/16 04:23:02 INFO : b/potato: Deleted 2025/04/16 04:23:03 INFO : a: Set directory modification time (using DirSetModTime) 2025/04/16 04:23:03 INFO : d/e: Removing directory 2025/04/16 04:23:04 INFO : d: Removing directory 2025/04/16 04:23:04 DEBUG : ka6id8d20d3s5ktapedlphgta8: Rmdir: contains trashed file: "r8sppajuabeak3sbgj2ak8vuf8" 2025/04/16 04:23:04 INFO : b: Removing directory 2025/04/16 04:23:05 DEBUG : 32d8ua6196mc1r7qkfog53rkg0: Rmdir: contains trashed file: "2m507n64kafsi59v9q71r281a4" 2025/04/16 04:23:05 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-biqaqid5vuba': deleted 3 directories run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-biqaqid5vuba'", Local "Local file system at /tmp/rclone2020710954", Modify Window "1ms" 2025/04/16 04:23:07 DEBUG : 3i9du405pfogq3ncai6pg7ouio: Rmdir: contains trashed file: "982d3pss7t5pn0il16r2foj31s" 2025/04/16 04:23:08 DEBUG : 2bsvlrk2ne1lfitm6tttcu0qt8: Rmdir: contains trashed file: "89l8renevh3mji1c8r1p7qn6tg" --- PASS: TestSyncAfterRemovingAFileAndAddingAFileSubDir (17.00s) === RUN TestSyncAfterRemovingAFileAndAddingAFileSubDirWithErrors run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-biqaqid5vuba'", Local "Local file system at /tmp/rclone2020710954", Modify Window "1ms" 2025/04/16 04:23:11 DEBUG : b/potato: md5 = 3886eeba8d2b92f1795e769ffb7b3f0d OK 2025/04/16 04:23:14 DEBUG : c/non empty space: md5 = 4e8ab136362b7d7488797252eb874d9f OK 2025/04/16 04:23:14 INFO : d: Making directory 2025/04/16 04:23:15 DEBUG : Added delayed dir = "a", newDst= 2025/04/16 04:23:16 INFO : c: Set directory modification time (using SetModTime) 2025/04/16 04:23:16 DEBUG : Added delayed dir = "c", newDst=c 2025/04/16 04:23:16 DEBUG : c/non empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/04/16 04:23:16 DEBUG : a/potato2: Need to transfer - File not found at Destination 2025/04/16 04:23:16 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-biqaqid5vuba': Waiting for checks to finish 2025/04/16 04:23:16 DEBUG : c/non empty space: Unchanged skipping 2025/04/16 04:23:16 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-biqaqid5vuba': Waiting for transfers to finish 2025/04/16 04:23:18 DEBUG : a/potato2: md5 = 9ea72ac2cc8f228b5dfe8f920ecebaef OK 2025/04/16 04:23:18 INFO : a/potato2: Copied (new) 2025/04/16 04:23:18 ERROR : Encrypted drive 'TestCryptDrive:rclone-test-biqaqid5vuba': not deleting files as there were IO errors 2025/04/16 04:23:19 INFO : a: Set directory modification time (using DirSetModTime) 2025/04/16 04:23:19 ERROR : Encrypted drive 'TestCryptDrive:rclone-test-biqaqid5vuba': not deleting directories as there were IO errors run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-biqaqid5vuba'", Local "Local file system at /tmp/rclone2020710954", Modify Window "1ms" 2025/04/16 04:23:22 DEBUG : 3i9du405pfogq3ncai6pg7ouio: Rmdir: contains trashed file: "982d3pss7t5pn0il16r2foj31s" 2025/04/16 04:23:23 DEBUG : 32d8ua6196mc1r7qkfog53rkg0: Rmdir: contains trashed file: "2m507n64kafsi59v9q71r281a4" 2025/04/16 04:23:23 DEBUG : 2bsvlrk2ne1lfitm6tttcu0qt8: Rmdir: contains trashed file: "89l8renevh3mji1c8r1p7qn6tg" --- PASS: TestSyncAfterRemovingAFileAndAddingAFileSubDirWithErrors (15.24s) === RUN TestSyncDeleteAfter --- PASS: TestSyncDeleteAfter (0.00s) === RUN TestSyncDeleteDuring run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-biqaqid5vuba'", Local "Local file system at /tmp/rclone2020710954", Modify Window "1ms" 2025/04/16 04:23:26 DEBUG : potato: md5 = 879517b7ba76f5a5d9060a5b8ec0de36 OK 2025/04/16 04:23:27 DEBUG : empty space: md5 = 1336ed1a3df4c42e2ba6b420869db8bc OK 2025/04/16 04:23:28 DEBUG : Waiting for deletions to finish 2025/04/16 04:23:28 DEBUG : empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/04/16 04:23:28 DEBUG : potato2: Need to transfer - File not found at Destination 2025/04/16 04:23:28 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-biqaqid5vuba': Waiting for checks to finish 2025/04/16 04:23:28 DEBUG : empty space: Unchanged skipping 2025/04/16 04:23:28 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-biqaqid5vuba': Waiting for transfers to finish 2025/04/16 04:23:28 INFO : potato: Deleted 2025/04/16 04:23:29 DEBUG : potato2: md5 = 662a3cba5c4e04bd9ff559c7782b0014 OK 2025/04/16 04:23:29 INFO : potato2: Copied (new) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-biqaqid5vuba'", Local "Local file system at /tmp/rclone2020710954", Modify Window "1ms" --- PASS: TestSyncDeleteDuring (6.83s) === RUN TestSyncDeleteBefore run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-biqaqid5vuba'", Local "Local file system at /tmp/rclone2020710954", Modify Window "1ms" 2025/04/16 04:23:33 DEBUG : potato: md5 = 035f86d4249f3e0306808f8cee835b33 OK 2025/04/16 04:23:34 DEBUG : empty space: md5 = d8cbbc90e8b9aa8235177bc76f03bab8 OK 2025/04/16 04:23:34 DEBUG : Waiting for deletions to finish 2025/04/16 04:23:35 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-biqaqid5vuba': Waiting for checks to finish 2025/04/16 04:23:35 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-biqaqid5vuba': Waiting for transfers to finish 2025/04/16 04:23:35 INFO : potato: Deleted 2025/04/16 04:23:35 DEBUG : empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/04/16 04:23:35 DEBUG : potato2: Need to transfer - File not found at Destination 2025/04/16 04:23:35 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-biqaqid5vuba': Waiting for checks to finish 2025/04/16 04:23:35 DEBUG : empty space: Unchanged skipping 2025/04/16 04:23:35 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-biqaqid5vuba': Waiting for transfers to finish 2025/04/16 04:23:37 DEBUG : potato2: md5 = 5c8e39ba40c738c5b69060cbe83bbdad OK 2025/04/16 04:23:37 INFO : potato2: Copied (new) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-biqaqid5vuba'", Local "Local file system at /tmp/rclone2020710954", Modify Window "1ms" --- PASS: TestSyncDeleteBefore (7.38s) === RUN TestCopyDeleteBefore run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-biqaqid5vuba'", Local "Local file system at /tmp/rclone2020710954", Modify Window "1ms" 2025/04/16 04:23:40 DEBUG : potato: md5 = f9f4a0a4111836c6d81df19e4630cd01 OK 2025/04/16 04:23:41 DEBUG : potato2: Need to transfer - File not found at Destination 2025/04/16 04:23:41 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-biqaqid5vuba': Waiting for checks to finish 2025/04/16 04:23:41 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-biqaqid5vuba': Waiting for transfers to finish 2025/04/16 04:23:42 DEBUG : potato2: md5 = a6bdeaba3a518d876c2d70730221cfe5 OK 2025/04/16 04:23:42 INFO : potato2: Copied (new) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-biqaqid5vuba'", Local "Local file system at /tmp/rclone2020710954", Modify Window "1ms" --- PASS: TestCopyDeleteBefore (5.21s) === RUN TestSyncWithExclude run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-biqaqid5vuba'", Local "Local file system at /tmp/rclone2020710954", Modify Window "1ms" 2025/04/16 04:23:45 DEBUG : potato2: md5 = 2f26e43ecabf4505b9ff3f989122b487 OK 2025/04/16 04:23:47 DEBUG : empty space: md5 = 3efeb4d7a3dfccaa4fc8f153477ca170 OK 2025/04/16 04:23:47 DEBUG : enormous: Excluded (Size Filter) 2025/04/16 04:23:47 DEBUG : enormous: Excluded 2025/04/16 04:23:47 DEBUG : potato2: Excluded (Size Filter) 2025/04/16 04:23:47 DEBUG : potato2: Excluded 2025/04/16 04:23:47 DEBUG : potato2: Excluded (Size Filter) 2025/04/16 04:23:47 DEBUG : empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/04/16 04:23:47 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-biqaqid5vuba': Waiting for checks to finish 2025/04/16 04:23:47 DEBUG : empty space: Unchanged skipping 2025/04/16 04:23:47 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-biqaqid5vuba': Waiting for transfers to finish 2025/04/16 04:23:47 DEBUG : Waiting for deletions to finish 2025/04/16 04:23:47 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-biqaqid5vuba'", Local "Local file system at /tmp/rclone2020710954", Modify Window "1ms" 2025/04/16 04:23:47 DEBUG : enormous: Excluded (Size Filter) 2025/04/16 04:23:47 DEBUG : enormous: Excluded 2025/04/16 04:23:47 DEBUG : potato2: Excluded (Size Filter) 2025/04/16 04:23:47 DEBUG : potato2: Excluded 2025/04/16 04:23:48 DEBUG : potato2: Excluded (Size Filter) 2025/04/16 04:23:48 DEBUG : empty space: Size and modification time the same (differ by 456.789µs, within tolerance 1ms) 2025/04/16 04:23:48 DEBUG : Local file system at /tmp/rclone2020710954: Waiting for checks to finish 2025/04/16 04:23:48 DEBUG : empty space: Unchanged skipping 2025/04/16 04:23:48 DEBUG : Local file system at /tmp/rclone2020710954: Waiting for transfers to finish 2025/04/16 04:23:48 DEBUG : Waiting for deletions to finish 2025/04/16 04:23:48 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-biqaqid5vuba'", Local "Local file system at /tmp/rclone2020710954", Modify Window "1ms" --- PASS: TestSyncWithExclude (6.05s) === RUN TestSyncWithExcludeAndDeleteExcluded run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-biqaqid5vuba'", Local "Local file system at /tmp/rclone2020710954", Modify Window "1ms" 2025/04/16 04:23:51 DEBUG : potato2: md5 = 41ced5425fdee3088ff7e4aefb5e711b OK 2025/04/16 04:23:53 DEBUG : empty space: md5 = 50b189a8128149bd4702e9e783efcebe OK 2025/04/16 04:23:54 DEBUG : enormous: md5 = 622ca41afe6f70048cc5148a89b3eaed OK 2025/04/16 04:23:54 DEBUG : enormous: Excluded (Size Filter) 2025/04/16 04:23:54 DEBUG : enormous: Excluded 2025/04/16 04:23:54 DEBUG : potato2: Excluded (Size Filter) 2025/04/16 04:23:54 DEBUG : potato2: Excluded 2025/04/16 04:23:55 DEBUG : empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/04/16 04:23:55 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-biqaqid5vuba': Waiting for checks to finish 2025/04/16 04:23:55 DEBUG : empty space: Unchanged skipping 2025/04/16 04:23:55 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-biqaqid5vuba': Waiting for transfers to finish 2025/04/16 04:23:55 DEBUG : Waiting for deletions to finish 2025/04/16 04:23:55 INFO : enormous: Deleted 2025/04/16 04:23:55 INFO : potato2: Deleted 2025/04/16 04:23:55 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-biqaqid5vuba'", Local "Local file system at /tmp/rclone2020710954", Modify Window "1ms" 2025/04/16 04:23:55 DEBUG : Local file system at /tmp/rclone2020710954: Waiting for checks to finish 2025/04/16 04:23:55 DEBUG : empty space: Size and modification time the same (differ by 456.789µs, within tolerance 1ms) 2025/04/16 04:23:55 DEBUG : empty space: Unchanged skipping 2025/04/16 04:23:55 DEBUG : Local file system at /tmp/rclone2020710954: Waiting for transfers to finish 2025/04/16 04:23:55 DEBUG : Waiting for deletions to finish 2025/04/16 04:23:55 INFO : enormous: Deleted 2025/04/16 04:23:55 INFO : potato2: Deleted 2025/04/16 04:23:55 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-biqaqid5vuba'", Local "Local file system at /tmp/rclone2020710954", Modify Window "1ms" --- PASS: TestSyncWithExcludeAndDeleteExcluded (7.41s) === RUN TestSyncWithUpdateOlder run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-biqaqid5vuba'", Local "Local file system at /tmp/rclone2020710954", Modify Window "1ms" 2025/04/16 04:23:59 DEBUG : one: md5 = d7b50b5aa1499c26a00d8e3f933ce730 OK 2025/04/16 04:24:00 DEBUG : two: md5 = 76bf00033e7a460804a4401cf6538d7e OK 2025/04/16 04:24:02 DEBUG : three: md5 = 0355621b6eca3821970a5724521271d5 OK 2025/04/16 04:24:03 DEBUG : four: md5 = c1937c5db5e8eccd0e1ee01cf7cd83c8 OK 2025/04/16 04:24:03 DEBUG : five: Need to transfer - File not found at Destination 2025/04/16 04:24:03 DEBUG : four: Sizes differ (src 4 vs dst 8) 2025/04/16 04:24:03 DEBUG : one: Destination is newer than source, skipping 2025/04/16 04:24:03 DEBUG : three: Sizes identical 2025/04/16 04:24:03 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-biqaqid5vuba': Waiting for checks to finish 2025/04/16 04:24:03 DEBUG : four: Destination mod time is within 1s of source but files differ, transferring 2025/04/16 04:24:03 DEBUG : three: Destination mod time is within 1s of source and files identical, skipping 2025/04/16 04:24:03 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-biqaqid5vuba': Waiting for transfers to finish 2025/04/16 04:24:05 DEBUG : two: md5 = 8455f3bbc846d1445e6910daf812352e OK 2025/04/16 04:24:05 INFO : two: Copied (replaced existing) 2025/04/16 04:24:05 DEBUG : four: md5 = 96d38e5dfafaee0f366f26361a34bf16 OK 2025/04/16 04:24:05 INFO : four: Copied (replaced existing) 2025/04/16 04:24:05 DEBUG : five: md5 = 460fa9a7b9a153d4811a491cb0a3d6b1 OK 2025/04/16 04:24:05 INFO : five: Copied (new) 2025/04/16 04:24:05 DEBUG : Waiting for deletions to finish sync_test.go:1449: Skip test with --checksum as no hashes supported --- PASS: TestSyncWithUpdateOlder (10.63s) === 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-biqaqid5vuba'", Local "Local file system at /tmp/rclone2020710954", Modify Window "1ms" sync_test.go:1538: Can track renames: false 2025/04/16 04:24:08 ERROR : Encrypted drive 'TestCryptDrive:rclone-test-biqaqid5vuba': Ignoring --track-renames as the source and destination do not have a common hash 2025/04/16 04:24:08 DEBUG : potato: Need to transfer - File not found at Destination 2025/04/16 04:24:08 DEBUG : yam: Need to transfer - File not found at Destination 2025/04/16 04:24:08 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-biqaqid5vuba': Waiting for checks to finish 2025/04/16 04:24:08 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-biqaqid5vuba': Waiting for transfers to finish 2025/04/16 04:24:09 DEBUG : yam: md5 = 70e8742bba7d0b9a5abf834f000eeddd OK 2025/04/16 04:24:09 INFO : yam: Copied (new) 2025/04/16 04:24:09 DEBUG : potato: md5 = 156d4cfe5c565dfc4346de53580c8257 OK 2025/04/16 04:24:09 INFO : potato: Copied (new) 2025/04/16 04:24:09 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-biqaqid5vuba'", Local "Local file system at /tmp/rclone2020710954", Modify Window "1ms" 2025/04/16 04:24:10 ERROR : Encrypted drive 'TestCryptDrive:rclone-test-biqaqid5vuba': Ignoring --track-renames as the source and destination do not have a common hash 2025/04/16 04:24:10 DEBUG : potato: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/16 04:24:10 DEBUG : yaml: Need to transfer - File not found at Destination 2025/04/16 04:24:10 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-biqaqid5vuba': Waiting for checks to finish 2025/04/16 04:24:10 DEBUG : potato: Unchanged skipping 2025/04/16 04:24:10 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-biqaqid5vuba': Waiting for transfers to finish 2025/04/16 04:24:11 DEBUG : yaml: md5 = 89a35cc8b7d302597c89205c518112e7 OK 2025/04/16 04:24:11 INFO : yaml: Copied (new) 2025/04/16 04:24:11 DEBUG : Waiting for deletions to finish 2025/04/16 04:24:12 INFO : yam: Deleted run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-biqaqid5vuba'", Local "Local file system at /tmp/rclone2020710954", Modify Window "1ms" --- PASS: TestSyncWithTrackRenames (6.24s) === RUN TestParseRenamesStrategyModtime --- PASS: TestParseRenamesStrategyModtime (0.00s) === RUN TestRenamesStrategyModtime --- PASS: TestRenamesStrategyModtime (0.00s) === RUN TestSyncWithTrackRenamesStrategyModtime run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-biqaqid5vuba'", Local "Local file system at /tmp/rclone2020710954", Modify Window "1ms" sync_test.go:1610: Can track renames: true 2025/04/16 04:24:14 INFO : Encrypted drive 'TestCryptDrive:rclone-test-biqaqid5vuba': Making map for --track-renames 2025/04/16 04:24:14 INFO : Encrypted drive 'TestCryptDrive:rclone-test-biqaqid5vuba': Finished making map for --track-renames 2025/04/16 04:24:14 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-biqaqid5vuba': Waiting for checks to finish 2025/04/16 04:24:14 DEBUG : potato: Need to transfer - No matching file found at Destination 2025/04/16 04:24:14 DEBUG : yam: Need to transfer - No matching file found at Destination 2025/04/16 04:24:14 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-biqaqid5vuba': Waiting for renames to finish 2025/04/16 04:24:14 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-biqaqid5vuba': Waiting for transfers to finish 2025/04/16 04:24:16 DEBUG : potato: md5 = 1f6d092707334331b8d9296eb34d7555 OK 2025/04/16 04:24:16 INFO : potato: Copied (new) 2025/04/16 04:24:16 DEBUG : yam: md5 = 3652e1289a14fe5efc0c062c0a1c4e70 OK 2025/04/16 04:24:16 INFO : yam: Copied (new) 2025/04/16 04:24:16 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-biqaqid5vuba'", Local "Local file system at /tmp/rclone2020710954", Modify Window "1ms" 2025/04/16 04:24:16 DEBUG : potato: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/16 04:24:16 INFO : Encrypted drive 'TestCryptDrive:rclone-test-biqaqid5vuba': Making map for --track-renames 2025/04/16 04:24:16 INFO : Encrypted drive 'TestCryptDrive:rclone-test-biqaqid5vuba': Finished making map for --track-renames 2025/04/16 04:24:16 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-biqaqid5vuba': Waiting for checks to finish 2025/04/16 04:24:16 DEBUG : potato: Unchanged skipping 2025/04/16 04:24:16 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-biqaqid5vuba': Waiting for renames to finish 2025/04/16 04:24:17 INFO : yam: Moved (server-side) to: yaml 2025/04/16 04:24:17 INFO : yaml: Renamed from "yam" 2025/04/16 04:24:17 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-biqaqid5vuba': Waiting for transfers to finish 2025/04/16 04:24:17 DEBUG : Waiting for deletions to finish 2025/04/16 04:24:17 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-biqaqid5vuba'", Local "Local file system at /tmp/rclone2020710954", Modify Window "1ms" --- PASS: TestSyncWithTrackRenamesStrategyModtime (5.38s) === RUN TestSyncWithTrackRenamesStrategyLeaf run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-biqaqid5vuba'", Local "Local file system at /tmp/rclone2020710954", Modify Window "1ms" sync_test.go:1649: Can track renames: true 2025/04/16 04:24:20 DEBUG : Added delayed dir = "sub", newDst= 2025/04/16 04:24:20 INFO : Encrypted drive 'TestCryptDrive:rclone-test-biqaqid5vuba': Making map for --track-renames 2025/04/16 04:24:20 INFO : Encrypted drive 'TestCryptDrive:rclone-test-biqaqid5vuba': Finished making map for --track-renames 2025/04/16 04:24:20 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-biqaqid5vuba': Waiting for checks to finish 2025/04/16 04:24:20 DEBUG : sub/yam: Need to transfer - No matching file found at Destination 2025/04/16 04:24:20 DEBUG : potato: Need to transfer - No matching file found at Destination 2025/04/16 04:24:20 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-biqaqid5vuba': Waiting for renames to finish 2025/04/16 04:24:20 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-biqaqid5vuba': Waiting for transfers to finish 2025/04/16 04:24:22 DEBUG : sub/yam: md5 = 5e9ce3d5748534eb5f53c7f3e877a120 OK 2025/04/16 04:24:22 INFO : sub/yam: Copied (new) 2025/04/16 04:24:22 DEBUG : potato: md5 = bba104ecb6588eecf2ff12fdd263dc12 OK 2025/04/16 04:24:22 INFO : potato: Copied (new) 2025/04/16 04:24:22 DEBUG : Waiting for deletions to finish 2025/04/16 04:24:23 INFO : sub: Set directory modification time (using DirSetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-biqaqid5vuba'", Local "Local file system at /tmp/rclone2020710954", Modify Window "1ms" 2025/04/16 04:24:24 DEBUG : potato: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/16 04:24:24 DEBUG : potato: Unchanged skipping 2025/04/16 04:24:24 INFO : sub: Set directory modification time (using SetModTime) 2025/04/16 04:24:24 DEBUG : Added delayed dir = "sub", newDst=sub 2025/04/16 04:24:24 INFO : Encrypted drive 'TestCryptDrive:rclone-test-biqaqid5vuba': Making map for --track-renames 2025/04/16 04:24:24 INFO : Encrypted drive 'TestCryptDrive:rclone-test-biqaqid5vuba': Finished making map for --track-renames 2025/04/16 04:24:24 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-biqaqid5vuba': Waiting for checks to finish 2025/04/16 04:24:24 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-biqaqid5vuba': Waiting for renames to finish 2025/04/16 04:24:25 INFO : sub/yam: Moved (server-side) to: yam 2025/04/16 04:24:25 INFO : yam: Renamed from "sub/yam" 2025/04/16 04:24:25 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-biqaqid5vuba': Waiting for transfers to finish 2025/04/16 04:24:25 DEBUG : Waiting for deletions to finish 2025/04/16 04:24:25 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-biqaqid5vuba'", Local "Local file system at /tmp/rclone2020710954", Modify Window "1ms" --- PASS: TestSyncWithTrackRenamesStrategyLeaf (8.76s) === RUN TestServerSideMoveLocal run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-biqaqid5vuba'", Local "Local file system at /tmp/rclone2020710954", Modify Window "1ms" 2025/04/16 04:24:28 DEBUG : Creating backend with remote "/tmp/rclone2020710954/dir1" 2025/04/16 04:24:28 DEBUG : Creating backend with remote "/tmp/rclone2020710954/dir2" 2025/04/16 04:24:28 DEBUG : Local file system at /tmp/rclone2020710954/dir2: Using server-side directory move 2025/04/16 04:24:28 INFO : Local file system at /tmp/rclone2020710954/dir2: Server side directory move failed - fallback to file moves: can't copy directory - destination already exists 2025/04/16 04:24:28 DEBUG : file1.txt: Need to transfer - File not found at Destination 2025/04/16 04:24:28 INFO : file1.txt: Moved (server-side) 2025/04/16 04:24:28 DEBUG : Local file system at /tmp/rclone2020710954/dir2: Waiting for checks to finish 2025/04/16 04:24:28 DEBUG : Local file system at /tmp/rclone2020710954/dir2: Waiting for transfers to finish --- PASS: TestServerSideMoveLocal (0.51s) === RUN TestMoveWithDeleteEmptySrcDirs run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-biqaqid5vuba'", Local "Local file system at /tmp/rclone2020710954", Modify Window "1ms" 2025/04/16 04:24:29 DEBUG : Added delayed dir = "nested", newDst= 2025/04/16 04:24:29 DEBUG : Added delayed dir = "sub dir", newDst= 2025/04/16 04:24:29 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2025/04/16 04:24:29 DEBUG : Added delayed dir = "nested/sub dir", newDst= 2025/04/16 04:24:29 DEBUG : nested/sub dir/file: Need to transfer - File not found at Destination 2025/04/16 04:24:29 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-biqaqid5vuba': Waiting for checks to finish 2025/04/16 04:24:29 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-biqaqid5vuba': Waiting for transfers to finish 2025/04/16 04:24:31 DEBUG : sub dir/hello world: md5 = 73e2c59101b4291606d36bf6a0ccc682 OK 2025/04/16 04:24:31 INFO : sub dir/hello world: Copied (new) 2025/04/16 04:24:31 INFO : sub dir/hello world: Deleted 2025/04/16 04:24:33 DEBUG : nested/sub dir/file: md5 = 5665e36a676837e8fe6a99c94e0efc07 OK 2025/04/16 04:24:33 INFO : nested/sub dir/file: Copied (new) 2025/04/16 04:24:33 INFO : nested/sub dir/file: Deleted 2025/04/16 04:24:33 INFO : nested/sub dir: Set directory modification time (using DirSetModTime) 2025/04/16 04:24:34 INFO : nested: Set directory modification time (using DirSetModTime) 2025/04/16 04:24:34 INFO : sub dir: Set directory modification time (using DirSetModTime) 2025/04/16 04:24:34 INFO : sub dir: Removing directory 2025/04/16 04:24:34 INFO : nested/sub dir: Removing directory 2025/04/16 04:24:34 INFO : nested: Removing directory 2025/04/16 04:24:34 DEBUG : Local file system at /tmp/rclone2020710954: deleted 3 directories run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-biqaqid5vuba'", Local "Local file system at /tmp/rclone2020710954", Modify Window "1ms" 2025/04/16 04:24:37 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" 2025/04/16 04:24:38 DEBUG : 37qp6d1gohacv723ij3brofbu8/14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "ftp4kuv8se7tqduu6pmmcvjsmk" 2025/04/16 04:24:38 DEBUG : 37qp6d1gohacv723ij3brofbu8: Rmdir: contains trashed file: "14begaa36ih249fgrnfk6nulg0" --- PASS: TestMoveWithDeleteEmptySrcDirs (10.58s) === RUN TestMoveWithoutDeleteEmptySrcDirs run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-biqaqid5vuba'", Local "Local file system at /tmp/rclone2020710954", Modify Window "1ms" 2025/04/16 04:24:40 DEBUG : Added delayed dir = "nested", newDst= 2025/04/16 04:24:40 DEBUG : Added delayed dir = "sub dir", newDst= 2025/04/16 04:24:40 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2025/04/16 04:24:40 DEBUG : Added delayed dir = "nested/sub dir", newDst= 2025/04/16 04:24:40 DEBUG : nested/sub dir/file: Need to transfer - File not found at Destination 2025/04/16 04:24:40 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-biqaqid5vuba': Waiting for checks to finish 2025/04/16 04:24:40 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-biqaqid5vuba': Waiting for transfers to finish 2025/04/16 04:24:42 DEBUG : sub dir/hello world: md5 = 49471e49228c5a06a5c8bfd6c149aae6 OK 2025/04/16 04:24:42 INFO : sub dir/hello world: Copied (new) 2025/04/16 04:24:42 INFO : sub dir/hello world: Deleted 2025/04/16 04:24:44 DEBUG : nested/sub dir/file: md5 = c204ff35984411e7d83443bbff607d84 OK 2025/04/16 04:24:44 INFO : nested/sub dir/file: Copied (new) 2025/04/16 04:24:44 INFO : nested/sub dir/file: Deleted 2025/04/16 04:24:44 INFO : nested/sub dir: Set directory modification time (using DirSetModTime) 2025/04/16 04:24:45 INFO : nested: Set directory modification time (using DirSetModTime) 2025/04/16 04:24:45 INFO : sub dir: Set directory modification time (using DirSetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-biqaqid5vuba'", Local "Local file system at /tmp/rclone2020710954", Modify Window "1ms" 2025/04/16 04:24:47 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" 2025/04/16 04:24:48 DEBUG : 37qp6d1gohacv723ij3brofbu8/14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "ftp4kuv8se7tqduu6pmmcvjsmk" 2025/04/16 04:24:49 DEBUG : 37qp6d1gohacv723ij3brofbu8: Rmdir: contains trashed file: "14begaa36ih249fgrnfk6nulg0" --- PASS: TestMoveWithoutDeleteEmptySrcDirs (10.44s) === RUN TestMoveWithIgnoreExisting run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-biqaqid5vuba'", Local "Local file system at /tmp/rclone2020710954", Modify Window "1ms" 2025/04/16 04:24:50 DEBUG : existing: Need to transfer - File not found at Destination 2025/04/16 04:24:50 DEBUG : existing-b: Need to transfer - File not found at Destination 2025/04/16 04:24:50 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-biqaqid5vuba': Waiting for checks to finish 2025/04/16 04:24:50 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-biqaqid5vuba': Waiting for transfers to finish 2025/04/16 04:24:51 DEBUG : existing-b: md5 = 22a9d409bcee6d4ba2a896afe2b033c5 OK 2025/04/16 04:24:51 INFO : existing-b: Copied (new) 2025/04/16 04:24:51 INFO : existing-b: Deleted 2025/04/16 04:24:52 DEBUG : existing: md5 = ce048a72f4df5505e4a2fabdcb246539 OK 2025/04/16 04:24:52 INFO : existing: Copied (new) 2025/04/16 04:24:52 INFO : existing: Deleted 2025/04/16 04:24:52 DEBUG : existing: Destination exists, skipping 2025/04/16 04:24:52 DEBUG : existing: Not removing source file as destination file exists and --ignore-existing is set 2025/04/16 04:24:52 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-biqaqid5vuba': Waiting for checks to finish 2025/04/16 04:24:52 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-biqaqid5vuba': Waiting for transfers to finish 2025/04/16 04:24:52 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-biqaqid5vuba'", Local "Local file system at /tmp/rclone2020710954", Modify Window "1ms" --- PASS: TestMoveWithIgnoreExisting (4.38s) === RUN TestServerSideMove run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-biqaqid5vuba'", Local "Local file system at /tmp/rclone2020710954", Modify Window "1ms" 2025/04/16 04:24:54 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-nayusuw0wuha" 2025/04/16 04:24:54 DEBUG : Creating backend with remote "TestDrive:crypt/asgo46uoahpjn0984kp14mg5b5arpqduim90f8kp6gmr7d7r8gl0" 2025/04/16 04:24:57 DEBUG : potato2: md5 = 03dee9f16f6da0f2d0bca67089b1e7c2 OK 2025/04/16 04:24:58 DEBUG : empty space: md5 = a07cc7cc47f469c2a66ad22f9f54700b OK 2025/04/16 04:25:00 DEBUG : potato3: md5 = b0c39cd37b4ff41345afc2daf81f3ac3 OK sync_test.go:1705: Server side move (if possible) Encrypted drive 'TestCryptDrive:rclone-test-biqaqid5vuba' -> Encrypted drive 'TestCryptDrive:rclone-test-nayusuw0wuha' 2025/04/16 04:25:02 DEBUG : empty space: md5 = fa434e8d3cd560cb56ee882ac18da906 OK 2025/04/16 04:25:04 DEBUG : potato3: md5 = 514b9b82aa6e3ac1a1e54063269221e2 OK 2025/04/16 04:25:04 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-nayusuw0wuha': Using server-side directory move 2025/04/16 04:25:04 INFO : Encrypted drive 'TestCryptDrive:rclone-test-nayusuw0wuha': Server side directory move failed - fallback to file moves: can't copy directory - destination already exists 2025/04/16 04:25:04 DEBUG : potato2: Need to transfer - File not found at Destination 2025/04/16 04:25:04 DEBUG : empty space: Size and modification time the same (differ by 0s, within tolerance 1ms) 2025/04/16 04:25:04 DEBUG : empty space: Unchanged skipping 2025/04/16 04:25:04 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-nayusuw0wuha': Waiting for checks to finish 2025/04/16 04:25:04 DEBUG : potato3: Sizes differ (src 68 vs dst 60) 2025/04/16 04:25:05 INFO : potato3: Deleted 2025/04/16 04:25:05 INFO : empty space: Deleted 2025/04/16 04:25:05 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-nayusuw0wuha': Waiting for transfers to finish 2025/04/16 04:25:05 INFO : potato2: Moved (server-side) 2025/04/16 04:25:05 INFO : potato3: Moved (server-side) 2025/04/16 04:25:06 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-qelugek8koru" 2025/04/16 04:25:06 DEBUG : Creating backend with remote "TestDrive:crypt/6vtcru1dli5bgh0hck856d32v8oj3rc5md1odc0rr51s25rv5sjg" 2025/04/16 04:25:07 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-qelugek8koru': Using server-side directory move 2025/04/16 04:25:07 INFO : Encrypted drive 'TestCryptDrive:rclone-test-qelugek8koru': Server side directory move succeeded 2025/04/16 04:25:08 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-qelugek8koru': Purge remote 2025/04/16 04:25:09 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-nayusuw0wuha': Purge remote 2025/04/16 04:25:09 NOTICE: purge failed: directory not found --- PASS: TestServerSideMove (15.24s) === RUN TestServerSideMoveWithFilter run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-biqaqid5vuba'", Local "Local file system at /tmp/rclone2020710954", Modify Window "1ms" 2025/04/16 04:25:10 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-riwoyof6ziqi" 2025/04/16 04:25:10 DEBUG : Creating backend with remote "TestDrive:crypt/m6d96t4981c073vpuqpr43do3s98c5o9pc28vfqr017mlfv09gag" 2025/04/16 04:25:12 DEBUG : potato2: md5 = a94b39419a70b40e94baacff9a96042a OK 2025/04/16 04:25:14 DEBUG : empty space: md5 = cbbd9963b3d22376650d6d06b109f43c OK 2025/04/16 04:25:15 DEBUG : potato3: md5 = 6a0e2e44c03da4466073624032e0e1dd OK sync_test.go:1705: Server side move (if possible) Encrypted drive 'TestCryptDrive:rclone-test-biqaqid5vuba' -> Encrypted drive 'TestCryptDrive:rclone-test-riwoyof6ziqi' 2025/04/16 04:25:17 DEBUG : empty space: md5 = ab47ba63a4e2a534c6af8327f98ab015 OK 2025/04/16 04:25:19 DEBUG : potato3: md5 = a8df81318d1d45f13764333027f2b29e OK 2025/04/16 04:25:19 DEBUG : empty space: Excluded (Size Filter) 2025/04/16 04:25:19 DEBUG : empty space: Excluded (Size Filter) 2025/04/16 04:25:19 DEBUG : potato2: Need to transfer - File not found at Destination 2025/04/16 04:25:19 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-riwoyof6ziqi': Waiting for checks to finish 2025/04/16 04:25:19 DEBUG : potato3: Sizes differ (src 68 vs dst 60) 2025/04/16 04:25:19 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-riwoyof6ziqi': Waiting for transfers to finish 2025/04/16 04:25:20 INFO : potato3: Deleted 2025/04/16 04:25:20 INFO : potato2: Moved (server-side) 2025/04/16 04:25:20 INFO : potato3: Moved (server-side) 2025/04/16 04:25:21 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-hupicec3taje" 2025/04/16 04:25:21 DEBUG : Creating backend with remote "TestDrive:crypt/516njtm919t47kudg38bege1s5epr2fqr2verg4lr0eb6ve9h9a0" 2025/04/16 04:25:22 DEBUG : empty space: Excluded (Size Filter) 2025/04/16 04:25:22 DEBUG : potato2: Need to transfer - File not found at Destination 2025/04/16 04:25:22 DEBUG : potato3: Need to transfer - File not found at Destination 2025/04/16 04:25:22 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hupicec3taje': Waiting for checks to finish 2025/04/16 04:25:22 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hupicec3taje': Waiting for transfers to finish 2025/04/16 04:25:24 INFO : potato2: Moved (server-side) 2025/04/16 04:25:24 INFO : potato3: Moved (server-side) 2025/04/16 04:25:25 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hupicec3taje': Purge remote 2025/04/16 04:25:25 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-riwoyof6ziqi': Purge remote --- PASS: TestServerSideMoveWithFilter (17.21s) === RUN TestServerSideMoveDeleteEmptySourceDirs run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-biqaqid5vuba'", Local "Local file system at /tmp/rclone2020710954", Modify Window "1ms" 2025/04/16 04:25:27 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-qixocut8woza" 2025/04/16 04:25:27 DEBUG : Creating backend with remote "TestDrive:crypt/4d0qqlvrvgctteeg83jt7653j21r0dmc5g2pnj65j380830hgas0" 2025/04/16 04:25:29 DEBUG : potato2: md5 = 9f6a36464c03ee775f46c4e359e2ccea OK 2025/04/16 04:25:31 DEBUG : empty space: md5 = 53240644cd024ff398f2ec381e34f2a6 OK 2025/04/16 04:25:32 DEBUG : potato3: md5 = cb2c21d31aa7fd8e70394d63ddcabec4 OK 2025/04/16 04:25:32 INFO : tomatoDir: Making directory sync_test.go:1705: Server side move (if possible) Encrypted drive 'TestCryptDrive:rclone-test-biqaqid5vuba' -> Encrypted drive 'TestCryptDrive:rclone-test-qixocut8woza' 2025/04/16 04:25:35 DEBUG : empty space: md5 = b3be90e79408e800ff813a5d12c222cb OK 2025/04/16 04:25:37 DEBUG : potato3: md5 = 784a4e01494466d1bb398d3e5039fc93 OK 2025/04/16 04:25:37 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-qixocut8woza': Using server-side directory move 2025/04/16 04:25:37 INFO : Encrypted drive 'TestCryptDrive:rclone-test-qixocut8woza': Server side directory move failed - fallback to file moves: can't copy directory - destination already exists 2025/04/16 04:25:37 DEBUG : potato2: Need to transfer - File not found at Destination 2025/04/16 04:25:37 DEBUG : Added delayed dir = "tomatoDir", newDst= 2025/04/16 04:25:37 DEBUG : empty space: Size and modification time the same (differ by 0s, within tolerance 1ms) 2025/04/16 04:25:37 DEBUG : empty space: Unchanged skipping 2025/04/16 04:25:37 DEBUG : potato3: Sizes differ (src 68 vs dst 60) 2025/04/16 04:25:37 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-qixocut8woza': Waiting for checks to finish 2025/04/16 04:25:38 INFO : empty space: Deleted 2025/04/16 04:25:38 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-qixocut8woza': Waiting for transfers to finish 2025/04/16 04:25:38 INFO : potato3: Deleted 2025/04/16 04:25:38 INFO : potato2: Moved (server-side) 2025/04/16 04:25:38 INFO : potato3: Moved (server-side) 2025/04/16 04:25:38 INFO : tomatoDir: Removing directory 2025/04/16 04:25:39 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-biqaqid5vuba': deleted 1 directories 2025/04/16 04:25:40 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-ferujef9wuxu" 2025/04/16 04:25:40 DEBUG : Creating backend with remote "TestDrive:crypt/hf69squ0g08mfbfhn0e9dvhhcan2t85jupkem9lphjgmlasd6aqg" 2025/04/16 04:25:41 INFO : tomatoDir: Making directory 2025/04/16 04:25:42 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-ferujef9wuxu': Using server-side directory move 2025/04/16 04:25:42 INFO : Encrypted drive 'TestCryptDrive:rclone-test-ferujef9wuxu': Server side directory move succeeded 2025/04/16 04:25:44 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-ferujef9wuxu': Purge remote 2025/04/16 04:25:44 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-qixocut8woza': Purge remote 2025/04/16 04:25:44 NOTICE: purge failed: directory not found --- PASS: TestServerSideMoveDeleteEmptySourceDirs (18.24s) === RUN TestServerSideMoveOverlap run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-biqaqid5vuba'", Local "Local file system at /tmp/rclone2020710954", Modify Window "1ms" sync_test.go:1910: Skipping test as remote supports DirMove --- SKIP: TestServerSideMoveOverlap (0.49s) === RUN TestSyncOverlap run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-biqaqid5vuba'", Local "Local file system at /tmp/rclone2020710954", Modify Window "1ms" 2025/04/16 04:25:45 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-biqaqid5vuba/rclone-sync-test" 2025/04/16 04:25:46 DEBUG : Creating backend with remote "TestDrive:crypt/9a87j16mtkuji9mc0peqjph2mbqrqnv6bm2vtfn0gamjmakcjej0/i7355aa0sb89uagn75vfjqr6s3e3e1h2et8in57abn1fe8qfego0" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-biqaqid5vuba'", Local "Local file system at /tmp/rclone2020710954", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-biqaqid5vuba'", Local "Local file system at /tmp/rclone2020710954", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-biqaqid5vuba'", Local "Local file system at /tmp/rclone2020710954", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-biqaqid5vuba'", Local "Local file system at /tmp/rclone2020710954", Modify Window "1ms" --- PASS: TestSyncOverlap (3.82s) === RUN TestSyncOverlapWithFilter run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-biqaqid5vuba'", Local "Local file system at /tmp/rclone2020710954", Modify Window "1ms" 2025/04/16 04:25:49 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-biqaqid5vuba/rclone-sync-test" 2025/04/16 04:25:49 DEBUG : Creating backend with remote "TestDrive:crypt/9a87j16mtkuji9mc0peqjph2mbqrqnv6bm2vtfn0gamjmakcjej0/i7355aa0sb89uagn75vfjqr6s3e3e1h2et8in57abn1fe8qfego0" 2025/04/16 04:25:51 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-biqaqid5vuba/rclone-sync-test-include/layer2" 2025/04/16 04:25:52 DEBUG : Creating backend with remote "TestDrive:crypt/9a87j16mtkuji9mc0peqjph2mbqrqnv6bm2vtfn0gamjmakcjej0/khf2vlblvnbf9ftevqm0htmss73hj1j5a7q328e4ohrgs7e2loe0/n01jpl9202nn9ec1rb75h0f1c4" 2025/04/16 04:25:55 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-biqaqid5vuba/rclone-sync-test-ignore-file" 2025/04/16 04:25:55 DEBUG : Creating backend with remote "TestDrive:crypt/9a87j16mtkuji9mc0peqjph2mbqrqnv6bm2vtfn0gamjmakcjej0/kmf11jujl9uha3tjganvgpkn45bu778hb5vb5riug1c26b38k7sg" 2025/04/16 04:25:59 DEBUG : rclone-sync-test-ignore-file/.ignore: md5 = 83382ed4529c4eed7eb77d2befe5ec43 OK 2025/04/16 04:26:01 DEBUG : Added delayed dir = "rclone-sync-test-include", newDst= 2025/04/16 04:26:01 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-biqaqid5vuba/rclone-sync-test': Waiting for checks to finish 2025/04/16 04:26:01 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-biqaqid5vuba/rclone-sync-test': Waiting for transfers to finish 2025/04/16 04:26:01 DEBUG : Waiting for deletions to finish 2025/04/16 04:26:01 INFO : There was nothing to transfer 2025/04/16 04:26:03 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-biqaqid5vuba': Waiting for checks to finish 2025/04/16 04:26:03 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-biqaqid5vuba': Waiting for transfers to finish 2025/04/16 04:26:03 DEBUG : Waiting for deletions to finish 2025/04/16 04:26:03 INFO : rclone-sync-test-include: Removing directory 2025/04/16 04:26:03 DEBUG : khf2vlblvnbf9ftevqm0htmss73hj1j5a7q328e4ohrgs7e2loe0: Rmdir: contains file: "n01jpl9202nn9ec1rb75h0f1c4" 2025/04/16 04:26:03 DEBUG : rclone-sync-test-include: Failed to Rmdir: directory not empty 2025/04/16 04:26:03 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-biqaqid5vuba': failed to delete 1 directories 2025/04/16 04:26:03 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-biqaqid5vuba'", Local "Local file system at /tmp/rclone2020710954", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-biqaqid5vuba'", Local "Local file system at /tmp/rclone2020710954", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-biqaqid5vuba'", Local "Local file system at /tmp/rclone2020710954", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-biqaqid5vuba'", Local "Local file system at /tmp/rclone2020710954", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-biqaqid5vuba'", Local "Local file system at /tmp/rclone2020710954", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-biqaqid5vuba'", Local "Local file system at /tmp/rclone2020710954", Modify Window "1ms" 2025/04/16 04:26:05 DEBUG : Added delayed dir = "rclone-sync-test-include", newDst= 2025/04/16 04:26:05 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-biqaqid5vuba/rclone-sync-test-include/layer2': Waiting for checks to finish 2025/04/16 04:26:05 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-biqaqid5vuba/rclone-sync-test-include/layer2': Waiting for transfers to finish 2025/04/16 04:26:05 DEBUG : Waiting for deletions to finish 2025/04/16 04:26:05 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-biqaqid5vuba'", Local "Local file system at /tmp/rclone2020710954", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-biqaqid5vuba'", Local "Local file system at /tmp/rclone2020710954", Modify Window "1ms" 2025/04/16 04:26:07 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-biqaqid5vuba': Waiting for checks to finish 2025/04/16 04:26:07 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-biqaqid5vuba': Waiting for transfers to finish 2025/04/16 04:26:07 DEBUG : Waiting for deletions to finish 2025/04/16 04:26:07 INFO : rclone-sync-test-include: Removing directory 2025/04/16 04:26:07 DEBUG : khf2vlblvnbf9ftevqm0htmss73hj1j5a7q328e4ohrgs7e2loe0: Rmdir: contains file: "n01jpl9202nn9ec1rb75h0f1c4" 2025/04/16 04:26:07 DEBUG : rclone-sync-test-include: Failed to Rmdir: directory not empty 2025/04/16 04:26:07 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-biqaqid5vuba': failed to delete 1 directories 2025/04/16 04:26:07 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-biqaqid5vuba'", Local "Local file system at /tmp/rclone2020710954", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-biqaqid5vuba'", Local "Local file system at /tmp/rclone2020710954", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-biqaqid5vuba'", Local "Local file system at /tmp/rclone2020710954", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-biqaqid5vuba'", Local "Local file system at /tmp/rclone2020710954", Modify Window "1ms" 2025/04/16 04:26:09 DEBUG : Added delayed dir = "rclone-sync-test-include", newDst= 2025/04/16 04:26:09 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-biqaqid5vuba/rclone-sync-test-ignore-file': Waiting for checks to finish 2025/04/16 04:26:09 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-biqaqid5vuba/rclone-sync-test-ignore-file': Waiting for transfers to finish 2025/04/16 04:26:09 DEBUG : Waiting for deletions to finish 2025/04/16 04:26:09 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-biqaqid5vuba'", Local "Local file system at /tmp/rclone2020710954", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-biqaqid5vuba'", Local "Local file system at /tmp/rclone2020710954", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-biqaqid5vuba'", Local "Local file system at /tmp/rclone2020710954", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-biqaqid5vuba'", Local "Local file system at /tmp/rclone2020710954", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-biqaqid5vuba'", Local "Local file system at /tmp/rclone2020710954", Modify Window "1ms" 2025/04/16 04:26:11 DEBUG : khf2vlblvnbf9ftevqm0htmss73hj1j5a7q328e4ohrgs7e2loe0: Rmdir: contains trashed file: "n01jpl9202nn9ec1rb75h0f1c4" 2025/04/16 04:26:12 DEBUG : kmf11jujl9uha3tjganvgpkn45bu778hb5vb5riug1c26b38k7sg: Rmdir: contains trashed file: "i0t74httmdlljg425j6tg570d8" --- PASS: TestSyncOverlapWithFilter (31.71s) === RUN TestSyncCompareDest run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-biqaqid5vuba'", Local "Local file system at /tmp/rclone2020710954", Modify Window "1ms" 2025/04/16 04:26:21 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-biqaqid5vuba/dst" 2025/04/16 04:26:21 DEBUG : Creating backend with remote "TestDrive:crypt/9a87j16mtkuji9mc0peqjph2mbqrqnv6bm2vtfn0gamjmakcjej0/31u3jie661vd5p8j7rtc3hgbh0" 2025/04/16 04:26:23 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-biqaqid5vuba/CompareDest" 2025/04/16 04:26:23 DEBUG : Creating backend with remote "TestDrive:crypt/9a87j16mtkuji9mc0peqjph2mbqrqnv6bm2vtfn0gamjmakcjej0/gveqi14airsml4bgu7krj116o8" 2025/04/16 04:26:25 DEBUG : one: Need to transfer - File not found at Destination 2025/04/16 04:26:25 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-biqaqid5vuba/dst': Waiting for checks to finish 2025/04/16 04:26:25 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-biqaqid5vuba/dst': Waiting for transfers to finish 2025/04/16 04:26:27 DEBUG : one: md5 = 6334e3990bb25f3ed135aa55a62700ae OK 2025/04/16 04:26:27 INFO : one: Copied (new) 2025/04/16 04:26:27 DEBUG : Waiting for deletions to finish 2025/04/16 04:26:28 DEBUG : one: Sizes differ (src 5 vs dst 3) 2025/04/16 04:26:28 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-biqaqid5vuba/dst': Waiting for checks to finish 2025/04/16 04:26:28 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-biqaqid5vuba/dst': Waiting for transfers to finish 2025/04/16 04:26:29 DEBUG : one: md5 = a9aa90bc49d3a6cb9258a3762d365dab OK 2025/04/16 04:26:29 INFO : one: Copied (replaced existing) 2025/04/16 04:26:29 DEBUG : Waiting for deletions to finish 2025/04/16 04:26:31 DEBUG : dst/one: md5 = 3eac90b841d2a8f45103d39c40c1bd12 OK 2025/04/16 04:26:33 DEBUG : CompareDest/one: md5 = 42ca3404cc4867bcccc3de2d00b5c62a OK 2025/04/16 04:26:34 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-biqaqid5vuba/dst': Waiting for checks to finish 2025/04/16 04:26:34 DEBUG : one: Sizes differ (src 5 vs dst 3) 2025/04/16 04:26:35 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/04/16 04:26:35 DEBUG : one: Destination found in --compare-dest, skipping 2025/04/16 04:26:35 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-biqaqid5vuba/dst': Waiting for transfers to finish 2025/04/16 04:26:35 DEBUG : Waiting for deletions to finish 2025/04/16 04:26:35 INFO : There was nothing to transfer 2025/04/16 04:26:36 DEBUG : CompareDest/two: md5 = bfc130d36c180ee97ed9979d3537ddf7 OK 2025/04/16 04:26:37 DEBUG : one: Sizes differ (src 5 vs dst 3) 2025/04/16 04:26:37 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/04/16 04:26:37 DEBUG : one: Destination found in --compare-dest, skipping 2025/04/16 04:26:37 DEBUG : two: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/04/16 04:26:37 DEBUG : two: Destination found in --compare-dest, skipping 2025/04/16 04:26:37 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-biqaqid5vuba/dst': Waiting for checks to finish 2025/04/16 04:26:37 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-biqaqid5vuba/dst': Waiting for transfers to finish 2025/04/16 04:26:37 DEBUG : Waiting for deletions to finish 2025/04/16 04:26:37 INFO : There was nothing to transfer 2025/04/16 04:26:38 DEBUG : one: Sizes differ (src 5 vs dst 3) 2025/04/16 04:26:39 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/04/16 04:26:39 DEBUG : one: Destination found in --compare-dest, skipping 2025/04/16 04:26:39 DEBUG : two: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/04/16 04:26:39 DEBUG : two: Destination found in --compare-dest, skipping 2025/04/16 04:26:39 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-biqaqid5vuba/dst': Waiting for checks to finish 2025/04/16 04:26:39 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-biqaqid5vuba/dst': Waiting for transfers to finish 2025/04/16 04:26:39 DEBUG : Waiting for deletions to finish 2025/04/16 04:26:39 INFO : There was nothing to transfer sync_test.go:2175: No hash on uploaded file so skipping compare timestamp test 2025/04/16 04:26:40 DEBUG : one: Sizes differ (src 5 vs dst 3) 2025/04/16 04:26:40 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/04/16 04:26:40 DEBUG : one: Destination found in --compare-dest, skipping 2025/04/16 04:26:40 DEBUG : two: Sizes differ (src 5 vs dst 3) 2025/04/16 04:26:40 DEBUG : two: Need to transfer - File not found at Destination 2025/04/16 04:26:40 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-biqaqid5vuba/dst': Waiting for checks to finish 2025/04/16 04:26:40 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-biqaqid5vuba/dst': Waiting for transfers to finish 2025/04/16 04:26:41 DEBUG : two: md5 = 5c95a416ef52fd5247ff122ecc248da5 OK 2025/04/16 04:26:41 INFO : two: Copied (new) 2025/04/16 04:26:41 DEBUG : Waiting for deletions to finish 2025/04/16 04:26:45 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k" 2025/04/16 04:26:45 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" 2025/04/16 04:26:45 DEBUG : gveqi14airsml4bgu7krj116o8: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k" 2025/04/16 04:26:45 DEBUG : gveqi14airsml4bgu7krj116o8: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" --- PASS: TestSyncCompareDest (25.18s) === RUN TestSyncMultipleCompareDest run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-biqaqid5vuba'", Local "Local file system at /tmp/rclone2020710954", Modify Window "1ms" 2025/04/16 04:26:48 DEBUG : pre-dest1/1: md5 = d57421dc7cce206ee3e6a4e68ae1e64b OK 2025/04/16 04:26:51 DEBUG : pre-dest2/2: md5 = cd79bd59cb3ab67821d657e74494e4b9 OK 2025/04/16 04:26:51 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-biqaqid5vuba/dest" 2025/04/16 04:26:51 DEBUG : Creating backend with remote "TestDrive:crypt/9a87j16mtkuji9mc0peqjph2mbqrqnv6bm2vtfn0gamjmakcjej0/rg03c1jvnehrrc617i0lnqjddc" 2025/04/16 04:26:53 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-biqaqid5vuba/pre-dest1" 2025/04/16 04:26:53 DEBUG : Creating backend with remote "TestDrive:crypt/9a87j16mtkuji9mc0peqjph2mbqrqnv6bm2vtfn0gamjmakcjej0/bbnblvh6k061ssopqrp18kd7gc" 2025/04/16 04:26:53 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-biqaqid5vuba/pre-dest2" 2025/04/16 04:26:54 DEBUG : Creating backend with remote "TestDrive:crypt/9a87j16mtkuji9mc0peqjph2mbqrqnv6bm2vtfn0gamjmakcjej0/dgicm1h6b5ejvlltm8eeif0bnk" 2025/04/16 04:26:55 DEBUG : 1: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/16 04:26:55 DEBUG : 1: Destination found in --compare-dest, skipping 2025/04/16 04:26:55 DEBUG : 2: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/16 04:26:55 DEBUG : 2: Destination found in --compare-dest, skipping 2025/04/16 04:26:56 DEBUG : 3: Need to transfer - File not found at Destination 2025/04/16 04:26:56 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-biqaqid5vuba/dest': Waiting for checks to finish 2025/04/16 04:26:56 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-biqaqid5vuba/dest': Waiting for transfers to finish 2025/04/16 04:26:58 DEBUG : 3: md5 = d741cd48658244fd78828a86f0199e69 OK 2025/04/16 04:26:58 INFO : 3: Copied (new) 2025/04/16 04:26:58 DEBUG : Waiting for deletions to finish 2025/04/16 04:27:01 DEBUG : dgicm1h6b5ejvlltm8eeif0bnk: Rmdir: contains trashed file: "1ghu8geql9vrl726n32nrf65bc" 2025/04/16 04:27:02 DEBUG : bbnblvh6k061ssopqrp18kd7gc: Rmdir: contains trashed file: "skbfko3oil7es0lj68ob574sro" 2025/04/16 04:27:02 DEBUG : rg03c1jvnehrrc617i0lnqjddc: Rmdir: contains trashed file: "g072p7hmjchlnj0gibe64c1epg" --- PASS: TestSyncMultipleCompareDest (16.80s) === RUN TestSyncCopyDest run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-biqaqid5vuba'", Local "Local file system at /tmp/rclone2020710954", Modify Window "1ms" 2025/04/16 04:27:03 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-biqaqid5vuba/dst" 2025/04/16 04:27:03 DEBUG : Creating backend with remote "TestDrive:crypt/9a87j16mtkuji9mc0peqjph2mbqrqnv6bm2vtfn0gamjmakcjej0/31u3jie661vd5p8j7rtc3hgbh0" 2025/04/16 04:27:04 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-biqaqid5vuba/CopyDest" 2025/04/16 04:27:05 DEBUG : Creating backend with remote "TestDrive:crypt/9a87j16mtkuji9mc0peqjph2mbqrqnv6bm2vtfn0gamjmakcjej0/d09o6po3f7bm6ce32vdgs8h9ls" 2025/04/16 04:27:07 DEBUG : one: Need to transfer - File not found at Destination 2025/04/16 04:27:07 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-biqaqid5vuba/dst': Waiting for checks to finish 2025/04/16 04:27:07 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-biqaqid5vuba/dst': Waiting for transfers to finish 2025/04/16 04:27:09 DEBUG : one: md5 = 92798536f2955fd9552eaf6727e0095e OK 2025/04/16 04:27:09 INFO : one: Copied (new) 2025/04/16 04:27:09 DEBUG : Waiting for deletions to finish 2025/04/16 04:27:10 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-biqaqid5vuba/dst': Waiting for checks to finish 2025/04/16 04:27:10 DEBUG : one: Sizes differ (src 5 vs dst 3) 2025/04/16 04:27:10 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-biqaqid5vuba/dst': Waiting for transfers to finish 2025/04/16 04:27:11 DEBUG : one: md5 = d20f77c724cd0e15e5b6ea315e0814e3 OK 2025/04/16 04:27:11 INFO : one: Copied (replaced existing) 2025/04/16 04:27:11 DEBUG : Waiting for deletions to finish 2025/04/16 04:27:13 DEBUG : dst/one: md5 = e0168fdc3b311a8eef4bb5d4ba10d773 OK 2025/04/16 04:27:15 DEBUG : CopyDest/one: md5 = 2785942682e8c7b82d3c3924b3c13ca2 OK 2025/04/16 04:27:16 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-biqaqid5vuba/BackupDir" 2025/04/16 04:27:16 DEBUG : Creating backend with remote "TestDrive:crypt/9a87j16mtkuji9mc0peqjph2mbqrqnv6bm2vtfn0gamjmakcjej0/s6dbk3lfi7c9kfvo6j7bla9m0g" 2025/04/16 04:27:18 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-biqaqid5vuba/dst': Waiting for checks to finish 2025/04/16 04:27:18 DEBUG : one: Sizes differ (src 5 vs dst 3) 2025/04/16 04:27:18 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/04/16 04:27:18 DEBUG : one: Sizes differ (src 5 vs dst 3) 2025/04/16 04:27:20 INFO : one: Moved (server-side) 2025/04/16 04:27:21 INFO : one: Copied (server-side copy) 2025/04/16 04:27:21 DEBUG : one: Destination found in --copy-dest, using server-side copy 2025/04/16 04:27:21 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-biqaqid5vuba/dst': Waiting for transfers to finish 2025/04/16 04:27:21 DEBUG : Waiting for deletions to finish 2025/04/16 04:27:23 DEBUG : CopyDest/two: md5 = b18eacdf77baa33af6cb594dce5439ee OK 2025/04/16 04:27:23 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/04/16 04:27:23 DEBUG : one: Unchanged skipping 2025/04/16 04:27:24 DEBUG : two: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/04/16 04:27:25 INFO : two: Copied (server-side copy) 2025/04/16 04:27:25 DEBUG : two: Destination found in --copy-dest, using server-side copy 2025/04/16 04:27:25 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-biqaqid5vuba/dst': Waiting for checks to finish 2025/04/16 04:27:25 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-biqaqid5vuba/dst': Waiting for transfers to finish 2025/04/16 04:27:25 DEBUG : Waiting for deletions to finish 2025/04/16 04:27:25 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/04/16 04:27:25 DEBUG : one: Unchanged skipping 2025/04/16 04:27:25 DEBUG : two: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/04/16 04:27:25 DEBUG : two: Unchanged skipping 2025/04/16 04:27:25 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-biqaqid5vuba/dst': Waiting for checks to finish 2025/04/16 04:27:25 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-biqaqid5vuba/dst': Waiting for transfers to finish 2025/04/16 04:27:25 DEBUG : Waiting for deletions to finish 2025/04/16 04:27:25 INFO : There was nothing to transfer 2025/04/16 04:27:27 DEBUG : CopyDest/three: md5 = d34746af14369822ada944f458b186e5 OK 2025/04/16 04:27:28 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/04/16 04:27:28 DEBUG : one: Unchanged skipping 2025/04/16 04:27:28 DEBUG : three: Sizes differ (src 7 vs dst 5) 2025/04/16 04:27:28 DEBUG : three: Destination not found in --copy-dest 2025/04/16 04:27:28 DEBUG : three: Need to transfer - File not found at Destination 2025/04/16 04:27:28 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-biqaqid5vuba/dst': Waiting for checks to finish 2025/04/16 04:27:28 DEBUG : two: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/04/16 04:27:28 DEBUG : two: Unchanged skipping 2025/04/16 04:27:28 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-biqaqid5vuba/dst': Waiting for transfers to finish 2025/04/16 04:27:30 DEBUG : three: md5 = 74f64bf88d094dfd1bfd4e8daeb695b0 OK 2025/04/16 04:27:30 INFO : three: Copied (new) 2025/04/16 04:27:30 DEBUG : Waiting for deletions to finish 2025/04/16 04:27:34 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "b6jdmn2b1adrhc8vikh7edr9os" 2025/04/16 04:27:34 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" 2025/04/16 04:27:34 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k" 2025/04/16 04:27:35 DEBUG : d09o6po3f7bm6ce32vdgs8h9ls: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k" 2025/04/16 04:27:35 DEBUG : d09o6po3f7bm6ce32vdgs8h9ls: Rmdir: contains trashed file: "b6jdmn2b1adrhc8vikh7edr9os" 2025/04/16 04:27:35 DEBUG : d09o6po3f7bm6ce32vdgs8h9ls: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" 2025/04/16 04:27:35 DEBUG : s6dbk3lfi7c9kfvo6j7bla9m0g: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" --- PASS: TestSyncCopyDest (33.10s) === RUN TestSyncBackupDir run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-biqaqid5vuba'", Local "Local file system at /tmp/rclone2020710954", Modify Window "1ms" 2025/04/16 04:27:38 DEBUG : dst/one: md5 = 0b151e09a5c6d86a8ed1fd9cdc02c4dc OK 2025/04/16 04:27:40 DEBUG : dst/two: md5 = ece925797237001015a12e7feea9b68e OK 2025/04/16 04:27:41 DEBUG : dst/three.txt: md5 = e1329f44901b0a3cf946a69290ec365c OK 2025/04/16 04:27:41 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-biqaqid5vuba/dst" 2025/04/16 04:27:42 DEBUG : Creating backend with remote "TestDrive:crypt/9a87j16mtkuji9mc0peqjph2mbqrqnv6bm2vtfn0gamjmakcjej0/31u3jie661vd5p8j7rtc3hgbh0" 2025/04/16 04:27:42 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-biqaqid5vuba/backup" 2025/04/16 04:27:42 DEBUG : Creating backend with remote "TestDrive:crypt/9a87j16mtkuji9mc0peqjph2mbqrqnv6bm2vtfn0gamjmakcjej0/1nrff024r7pq65ecp72fc28jb0" 2025/04/16 04:27:44 DEBUG : one: Sizes differ (src 4 vs dst 3) 2025/04/16 04:27:44 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/16 04:27:44 DEBUG : two: Unchanged skipping 2025/04/16 04:27:44 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-biqaqid5vuba/dst': Waiting for checks to finish 2025/04/16 04:27:46 INFO : one: Moved (server-side) 2025/04/16 04:27:46 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-biqaqid5vuba/dst': Waiting for transfers to finish 2025/04/16 04:27:47 DEBUG : one: md5 = a7881db250ca01eab0890b40e455a7dd OK 2025/04/16 04:27:47 INFO : one: Copied (new) 2025/04/16 04:27:47 DEBUG : Waiting for deletions to finish 2025/04/16 04:27:48 INFO : three.txt: Moved (server-side) 2025/04/16 04:27:48 INFO : three.txt: Moved into backup dir 2025/04/16 04:27:50 DEBUG : dst/three.txt: md5 = ab6116058708f94bdcdfafe8e8a0c910 OK 2025/04/16 04:27:50 DEBUG : one: Sizes differ (src 5 vs dst 4) 2025/04/16 04:27:50 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/16 04:27:50 DEBUG : two: Unchanged skipping 2025/04/16 04:27:50 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-biqaqid5vuba/dst': Waiting for checks to finish 2025/04/16 04:27:51 INFO : one: Deleted 2025/04/16 04:27:52 INFO : one: Moved (server-side) 2025/04/16 04:27:52 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-biqaqid5vuba/dst': Waiting for transfers to finish 2025/04/16 04:27:53 DEBUG : one: md5 = bc123b6b310ad9e25df7e3ec4c4bce3a OK 2025/04/16 04:27:53 INFO : one: Copied (new) 2025/04/16 04:27:53 DEBUG : Waiting for deletions to finish 2025/04/16 04:27:54 INFO : three.txt: Deleted 2025/04/16 04:27:54 INFO : three.txt: Moved (server-side) 2025/04/16 04:27:54 INFO : three.txt: Moved into backup dir 2025/04/16 04:27:58 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" 2025/04/16 04:27:58 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k" 2025/04/16 04:27:58 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" 2025/04/16 04:27:58 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "tr2hj63d80ftlmvm6a952snjcc" 2025/04/16 04:27:58 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "tr2hj63d80ftlmvm6a952snjcc" 2025/04/16 04:27:58 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" --- PASS: TestSyncBackupDir (22.87s) === RUN TestSyncBackupDirWithSuffix run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-biqaqid5vuba'", Local "Local file system at /tmp/rclone2020710954", Modify Window "1ms" 2025/04/16 04:28:01 DEBUG : dst/one: md5 = 3bbbe81aa195652c418bce1f9948c5d9 OK 2025/04/16 04:28:03 DEBUG : dst/two: md5 = b5f60c3139793e7e3483917e0e6db98a OK 2025/04/16 04:28:04 DEBUG : dst/three.txt: md5 = f15a98d198b0a3e44fba6b1c6b06a69e OK 2025/04/16 04:28:05 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-biqaqid5vuba/dst" 2025/04/16 04:28:05 DEBUG : Creating backend with remote "TestDrive:crypt/9a87j16mtkuji9mc0peqjph2mbqrqnv6bm2vtfn0gamjmakcjej0/31u3jie661vd5p8j7rtc3hgbh0" 2025/04/16 04:28:05 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-biqaqid5vuba/backup" 2025/04/16 04:28:05 DEBUG : Creating backend with remote "TestDrive:crypt/9a87j16mtkuji9mc0peqjph2mbqrqnv6bm2vtfn0gamjmakcjej0/1nrff024r7pq65ecp72fc28jb0" 2025/04/16 04:28:07 DEBUG : one: Sizes differ (src 4 vs dst 3) 2025/04/16 04:28:07 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-biqaqid5vuba/dst': Waiting for checks to finish 2025/04/16 04:28:07 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/16 04:28:07 DEBUG : two: Unchanged skipping 2025/04/16 04:28:09 INFO : one: Moved (server-side) to: one.bak 2025/04/16 04:28:09 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-biqaqid5vuba/dst': Waiting for transfers to finish 2025/04/16 04:28:10 DEBUG : one: md5 = 8a9dee5b13565a0fdf222b15e2f5f3b5 OK 2025/04/16 04:28:10 INFO : one: Copied (new) 2025/04/16 04:28:10 DEBUG : Waiting for deletions to finish 2025/04/16 04:28:11 INFO : three.txt: Moved (server-side) to: three.txt.bak 2025/04/16 04:28:11 INFO : three.txt: Moved into backup dir 2025/04/16 04:28:13 DEBUG : dst/three.txt: md5 = 3bd0767cf3feb442c0829c347af77fc1 OK 2025/04/16 04:28:14 DEBUG : one: Sizes differ (src 5 vs dst 4) 2025/04/16 04:28:14 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-biqaqid5vuba/dst': Waiting for checks to finish 2025/04/16 04:28:14 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/16 04:28:14 DEBUG : two: Unchanged skipping 2025/04/16 04:28:14 INFO : one.bak: Deleted 2025/04/16 04:28:15 INFO : one: Moved (server-side) to: one.bak 2025/04/16 04:28:15 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-biqaqid5vuba/dst': Waiting for transfers to finish 2025/04/16 04:28:16 DEBUG : one: md5 = 52e5adf0d114595d8f313ca43e24adc5 OK 2025/04/16 04:28:16 INFO : one: Copied (new) 2025/04/16 04:28:16 DEBUG : Waiting for deletions to finish 2025/04/16 04:28:17 INFO : three.txt.bak: Deleted 2025/04/16 04:28:18 INFO : three.txt: Moved (server-side) to: three.txt.bak 2025/04/16 04:28:18 INFO : three.txt: Moved into backup dir 2025/04/16 04:28:21 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" 2025/04/16 04:28:21 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k" 2025/04/16 04:28:21 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "sk91qgsqfn0r271r2ehsaoc20c" 2025/04/16 04:28:21 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "qltcak2uaegtmcoa8vijdppbp8" 2025/04/16 04:28:21 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "qltcak2uaegtmcoa8vijdppbp8" 2025/04/16 04:28:21 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "sk91qgsqfn0r271r2ehsaoc20c" --- PASS: TestSyncBackupDirWithSuffix (23.20s) === RUN TestSyncBackupDirWithSuffixKeepExtension run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-biqaqid5vuba'", Local "Local file system at /tmp/rclone2020710954", Modify Window "1ms" 2025/04/16 04:28:24 DEBUG : dst/one: md5 = 7f42a5c9140d096249d93d62722756dc OK 2025/04/16 04:28:26 DEBUG : dst/two: md5 = 2fbfd81aff5b8d739368d48a75fcf4c0 OK 2025/04/16 04:28:27 DEBUG : dst/three.txt: md5 = b0badbbfacf229b2716efcc12e9e24a1 OK 2025/04/16 04:28:28 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-biqaqid5vuba/dst" 2025/04/16 04:28:28 DEBUG : Creating backend with remote "TestDrive:crypt/9a87j16mtkuji9mc0peqjph2mbqrqnv6bm2vtfn0gamjmakcjej0/31u3jie661vd5p8j7rtc3hgbh0" 2025/04/16 04:28:28 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-biqaqid5vuba/backup" 2025/04/16 04:28:28 DEBUG : Creating backend with remote "TestDrive:crypt/9a87j16mtkuji9mc0peqjph2mbqrqnv6bm2vtfn0gamjmakcjej0/1nrff024r7pq65ecp72fc28jb0" 2025/04/16 04:28:30 DEBUG : one: Sizes differ (src 4 vs dst 3) 2025/04/16 04:28:30 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-biqaqid5vuba/dst': Waiting for checks to finish 2025/04/16 04:28:30 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/16 04:28:30 DEBUG : two: Unchanged skipping 2025/04/16 04:28:32 INFO : one: Moved (server-side) to: one-2019-01-01 2025/04/16 04:28:32 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-biqaqid5vuba/dst': Waiting for transfers to finish 2025/04/16 04:28:33 DEBUG : one: md5 = db0bf00aa2e0ed43821802e7df92344c OK 2025/04/16 04:28:33 INFO : one: Copied (new) 2025/04/16 04:28:33 DEBUG : Waiting for deletions to finish 2025/04/16 04:28:34 INFO : three.txt: Moved (server-side) to: three-2019-01-01.txt 2025/04/16 04:28:34 INFO : three.txt: Moved into backup dir 2025/04/16 04:28:36 DEBUG : dst/three.txt: md5 = 27d25d7d0f1638d8e2bf76dc7f53b8ce OK 2025/04/16 04:28:36 DEBUG : one: Sizes differ (src 5 vs dst 4) 2025/04/16 04:28:36 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/16 04:28:36 DEBUG : two: Unchanged skipping 2025/04/16 04:28:36 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-biqaqid5vuba/dst': Waiting for checks to finish 2025/04/16 04:28:37 INFO : one-2019-01-01: Deleted 2025/04/16 04:28:38 INFO : one: Moved (server-side) to: one-2019-01-01 2025/04/16 04:28:38 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-biqaqid5vuba/dst': Waiting for transfers to finish 2025/04/16 04:28:39 DEBUG : one: md5 = 65da02f8e837df4d9375f71b4811c30c OK 2025/04/16 04:28:39 INFO : one: Copied (new) 2025/04/16 04:28:39 DEBUG : Waiting for deletions to finish 2025/04/16 04:28:40 INFO : three-2019-01-01.txt: Deleted 2025/04/16 04:28:40 INFO : three.txt: Moved (server-side) to: three-2019-01-01.txt 2025/04/16 04:28:40 INFO : three.txt: Moved into backup dir 2025/04/16 04:28:43 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" 2025/04/16 04:28:43 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k" 2025/04/16 04:28:44 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "qtq2f6qq4lgpsmj88vb7147qje3prudmtfdtr2342fth58vo9a50" 2025/04/16 04:28:44 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "jcjl1bv3ep0v8kt35lqql1co90" 2025/04/16 04:28:44 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "qtq2f6qq4lgpsmj88vb7147qje3prudmtfdtr2342fth58vo9a50" 2025/04/16 04:28:44 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "jcjl1bv3ep0v8kt35lqql1co90" --- PASS: TestSyncBackupDirWithSuffixKeepExtension (22.72s) === RUN TestSyncBackupDirSuffixOnly run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-biqaqid5vuba'", Local "Local file system at /tmp/rclone2020710954", Modify Window "1ms" 2025/04/16 04:28:47 DEBUG : dst/one: md5 = 59402b961e74baed5ff21512cdc1086f OK 2025/04/16 04:28:48 DEBUG : dst/two: md5 = 3b8c4cbf333fc592dec0a78befa195bc OK 2025/04/16 04:28:50 DEBUG : dst/three.txt: md5 = 4f19452568421a1d1067782f55c6f8fa OK 2025/04/16 04:28:50 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-biqaqid5vuba/dst" 2025/04/16 04:28:50 DEBUG : Config file has changed externally - reloading 2025/04/16 04:28:50 DEBUG : Creating backend with remote "TestDrive:crypt/9a87j16mtkuji9mc0peqjph2mbqrqnv6bm2vtfn0gamjmakcjej0/31u3jie661vd5p8j7rtc3hgbh0" 2025/04/16 04:28:51 DEBUG : one: Sizes differ (src 4 vs dst 3) 2025/04/16 04:28:51 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/16 04:28:51 DEBUG : two: Unchanged skipping 2025/04/16 04:28:51 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-biqaqid5vuba/dst': Waiting for checks to finish 2025/04/16 04:28:52 INFO : one: Moved (server-side) to: one.bak 2025/04/16 04:28:52 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-biqaqid5vuba/dst': Waiting for transfers to finish 2025/04/16 04:28:53 DEBUG : one: md5 = 667bf155dfdbf4969ee7706efc7e2bec OK 2025/04/16 04:28:53 INFO : one: Copied (new) 2025/04/16 04:28:53 DEBUG : Waiting for deletions to finish 2025/04/16 04:28:54 INFO : three.txt: Moved (server-side) to: three.txt.bak 2025/04/16 04:28:54 INFO : three.txt: Moved into backup dir 2025/04/16 04:28:56 DEBUG : dst/three.txt: md5 = 51b3d4a634edc95be6504581bd4026ec OK 2025/04/16 04:28:56 DEBUG : one.bak: Excluded (Path Filter) 2025/04/16 04:28:56 DEBUG : three.txt.bak: Excluded (Path Filter) 2025/04/16 04:28:56 DEBUG : one: Sizes differ (src 5 vs dst 4) 2025/04/16 04:28:56 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/16 04:28:56 DEBUG : two: Unchanged skipping 2025/04/16 04:28:56 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-biqaqid5vuba/dst': Waiting for checks to finish 2025/04/16 04:28:57 INFO : one.bak: Deleted 2025/04/16 04:28:58 INFO : one: Moved (server-side) to: one.bak 2025/04/16 04:28:58 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-biqaqid5vuba/dst': Waiting for transfers to finish 2025/04/16 04:28:59 DEBUG : one: md5 = 2b143baa273015fec9241ac500887fa2 OK 2025/04/16 04:28:59 INFO : one: Copied (new) 2025/04/16 04:28:59 DEBUG : Waiting for deletions to finish 2025/04/16 04:29:00 INFO : three.txt.bak: Deleted 2025/04/16 04:29:00 INFO : three.txt: Moved (server-side) to: three.txt.bak 2025/04/16 04:29:00 INFO : three.txt: Moved into backup dir 2025/04/16 04:29:03 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" 2025/04/16 04:29:03 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "qltcak2uaegtmcoa8vijdppbp8" 2025/04/16 04:29:03 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "sk91qgsqfn0r271r2ehsaoc20c" 2025/04/16 04:29:03 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "qltcak2uaegtmcoa8vijdppbp8" 2025/04/16 04:29:03 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k" 2025/04/16 04:29:03 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "sk91qgsqfn0r271r2ehsaoc20c" --- PASS: TestSyncBackupDirSuffixOnly (19.05s) === RUN TestSyncSuffix run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-biqaqid5vuba'", Local "Local file system at /tmp/rclone2020710954", Modify Window "1ms" 2025/04/16 04:29:06 DEBUG : dst/one: md5 = 00c020eaf42c05070d5a3e1a7642bb59 OK 2025/04/16 04:29:08 DEBUG : dst/two: md5 = e07a5d2166bcd613ccc19cc94739218f OK 2025/04/16 04:29:09 DEBUG : dst/three.txt: md5 = b8e34aeb0e2ff2eb724d588bf7ff9a64 OK 2025/04/16 04:29:10 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-biqaqid5vuba/dst" 2025/04/16 04:29:10 DEBUG : Creating backend with remote "TestDrive:crypt/9a87j16mtkuji9mc0peqjph2mbqrqnv6bm2vtfn0gamjmakcjej0/31u3jie661vd5p8j7rtc3hgbh0" 2025/04/16 04:29:11 DEBUG : one: Sizes differ (src 4 vs dst 3) 2025/04/16 04:29:11 INFO : one: Moved (server-side) to: one.bak 2025/04/16 04:29:13 DEBUG : one: md5 = 4a8ad8343375613a6165580ae1b03457 OK 2025/04/16 04:29:13 INFO : one: Copied (new) 2025/04/16 04:29:13 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/16 04:29:13 DEBUG : two: Unchanged skipping 2025/04/16 04:29:13 DEBUG : three.txt: Sizes differ (src 6 vs dst 5) 2025/04/16 04:29:14 INFO : three.txt: Moved (server-side) to: three.txt.bak 2025/04/16 04:29:15 DEBUG : three.txt: md5 = 1a74bfa90392d48e9007ab995975d8d0 OK 2025/04/16 04:29:15 INFO : three.txt: Copied (new) 2025/04/16 04:29:17 DEBUG : one: Sizes differ (src 5 vs dst 4) 2025/04/16 04:29:17 INFO : one.bak: Deleted 2025/04/16 04:29:18 INFO : one: Moved (server-side) to: one.bak 2025/04/16 04:29:19 DEBUG : one: md5 = c0c5064c82dac6799062118c57be09b8 OK 2025/04/16 04:29:19 INFO : one: Copied (new) 2025/04/16 04:29:19 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/16 04:29:19 DEBUG : two: Unchanged skipping 2025/04/16 04:29:19 DEBUG : three.txt: Sizes differ (src 19 vs dst 6) 2025/04/16 04:29:20 INFO : three.txt.bak: Deleted 2025/04/16 04:29:21 INFO : three.txt: Moved (server-side) to: three.txt.bak 2025/04/16 04:29:22 DEBUG : three.txt: md5 = 79c80caae56b6e547df494c391163f99 OK 2025/04/16 04:29:22 INFO : three.txt: Copied (new) 2025/04/16 04:29:26 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "tr2hj63d80ftlmvm6a952snjcc" 2025/04/16 04:29:26 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" 2025/04/16 04:29:26 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "qltcak2uaegtmcoa8vijdppbp8" 2025/04/16 04:29:26 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "qltcak2uaegtmcoa8vijdppbp8" 2025/04/16 04:29:26 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "sk91qgsqfn0r271r2ehsaoc20c" 2025/04/16 04:29:26 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k" 2025/04/16 04:29:26 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "sk91qgsqfn0r271r2ehsaoc20c" --- PASS: TestSyncSuffix (22.38s) === RUN TestSyncSuffixKeepExtension run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-biqaqid5vuba'", Local "Local file system at /tmp/rclone2020710954", Modify Window "1ms" 2025/04/16 04:29:28 DEBUG : dst/one: md5 = 4de98bd062e964763bfafbbe832d0c2e OK 2025/04/16 04:29:30 DEBUG : dst/two: md5 = 8c03b6d3084f99b0cc0b346b63157b09 OK 2025/04/16 04:29:31 DEBUG : dst/three.txt: md5 = 60443b1dc493ac08bdf05fe4b67dfbaf OK 2025/04/16 04:29:32 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-biqaqid5vuba/dst" 2025/04/16 04:29:32 DEBUG : Creating backend with remote "TestDrive:crypt/9a87j16mtkuji9mc0peqjph2mbqrqnv6bm2vtfn0gamjmakcjej0/31u3jie661vd5p8j7rtc3hgbh0" 2025/04/16 04:29:33 DEBUG : one: Sizes differ (src 4 vs dst 3) 2025/04/16 04:29:33 INFO : one: Moved (server-side) to: one-2019-01-01 2025/04/16 04:29:35 DEBUG : one: md5 = 705da0d947d458e063339e20e8a7fe92 OK 2025/04/16 04:29:35 INFO : one: Copied (new) 2025/04/16 04:29:35 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/16 04:29:35 DEBUG : two: Unchanged skipping 2025/04/16 04:29:35 DEBUG : three.txt: Sizes differ (src 6 vs dst 5) 2025/04/16 04:29:36 INFO : three.txt: Moved (server-side) to: three-2019-01-01.txt 2025/04/16 04:29:37 DEBUG : three.txt: md5 = dac17743d3fe0d45440b7297edd83052 OK 2025/04/16 04:29:37 INFO : three.txt: Copied (new) 2025/04/16 04:29:39 DEBUG : one: Sizes differ (src 5 vs dst 4) 2025/04/16 04:29:39 INFO : one-2019-01-01: Deleted 2025/04/16 04:29:40 INFO : one: Moved (server-side) to: one-2019-01-01 2025/04/16 04:29:41 DEBUG : one: md5 = baddd95afc91aff303a317ad7eff9eb1 OK 2025/04/16 04:29:41 INFO : one: Copied (new) 2025/04/16 04:29:41 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/16 04:29:41 DEBUG : two: Unchanged skipping 2025/04/16 04:29:42 DEBUG : three.txt: Sizes differ (src 19 vs dst 6) 2025/04/16 04:29:42 INFO : three-2019-01-01.txt: Deleted 2025/04/16 04:29:43 INFO : three.txt: Moved (server-side) to: three-2019-01-01.txt 2025/04/16 04:29:44 DEBUG : three.txt: md5 = d31c8ed7b83ce88775313ad2dcf31f9b OK 2025/04/16 04:29:44 INFO : three.txt: Copied (new) 2025/04/16 04:29:48 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" 2025/04/16 04:29:48 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "tr2hj63d80ftlmvm6a952snjcc" 2025/04/16 04:29:48 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "jcjl1bv3ep0v8kt35lqql1co90" 2025/04/16 04:29:48 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "qtq2f6qq4lgpsmj88vb7147qje3prudmtfdtr2342fth58vo9a50" 2025/04/16 04:29:48 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "jcjl1bv3ep0v8kt35lqql1co90" 2025/04/16 04:29:48 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k" 2025/04/16 04:29:48 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "qtq2f6qq4lgpsmj88vb7147qje3prudmtfdtr2342fth58vo9a50" --- PASS: TestSyncSuffixKeepExtension (22.03s) === RUN TestSyncUTFNorm run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-biqaqid5vuba'", Local "Local file system at /tmp/rclone2020710954", Modify Window "1ms" 2025/04/16 04:29:50 DEBUG : Testêé: md5 = 2c874fd9b0e970754df1961b12b4d084 OK 2025/04/16 04:29:50 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-biqaqid5vuba': Waiting for checks to finish 2025/04/16 04:29:50 DEBUG : Testêé: Sizes differ (src 14 vs dst 18) 2025/04/16 04:29:50 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-biqaqid5vuba': Waiting for transfers to finish 2025/04/16 04:29:51 DEBUG : Testêé: md5 = 671f5b40ec331987147ba9e3370d0a9e OK 2025/04/16 04:29:51 INFO : Testêé: Copied (replaced existing) to: Testêé 2025/04/16 04:29:51 DEBUG : Waiting for deletions to finish --- PASS: TestSyncUTFNorm (4.26s) === RUN TestSyncImmutable run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-biqaqid5vuba'", Local "Local file system at /tmp/rclone2020710954", Modify Window "1ms" 2025/04/16 04:29:53 DEBUG : existing: Need to transfer - File not found at Destination 2025/04/16 04:29:53 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-biqaqid5vuba': Waiting for checks to finish 2025/04/16 04:29:53 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-biqaqid5vuba': Waiting for transfers to finish 2025/04/16 04:29:54 DEBUG : existing: md5 = ab977f3e3ef03924a859e36f41abc04c OK 2025/04/16 04:29:54 INFO : existing: Copied (new) 2025/04/16 04:29:54 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-biqaqid5vuba'", Local "Local file system at /tmp/rclone2020710954", Modify Window "1ms" 2025/04/16 04:29:55 DEBUG : existing: Sizes differ (src 8 vs dst 6) 2025/04/16 04:29:55 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-biqaqid5vuba': Waiting for checks to finish 2025/04/16 04:29:55 ERROR : existing: Source and destination exist but do not match: immutable file modified 2025/04/16 04:29:55 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-biqaqid5vuba': Waiting for transfers to finish 2025/04/16 04:29:55 ERROR : Encrypted drive 'TestCryptDrive:rclone-test-biqaqid5vuba': not deleting files as there were IO errors 2025/04/16 04:29:55 ERROR : Encrypted drive 'TestCryptDrive:rclone-test-biqaqid5vuba': not deleting directories as there were IO errors run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-biqaqid5vuba'", Local "Local file system at /tmp/rclone2020710954", Modify Window "1ms" --- PASS: TestSyncImmutable (4.62s) === RUN TestSyncIgnoreCase run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-biqaqid5vuba'", Local "Local file system at /tmp/rclone2020710954", Modify Window "1ms" 2025/04/16 04:29:59 DEBUG : EXISTING: md5 = 04621edf48921e14cc4aad3ddf9b1743 OK 2025/04/16 04:29:59 DEBUG : existing: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/16 04:29:59 DEBUG : existing: Unchanged skipping 2025/04/16 04:29:59 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-biqaqid5vuba': Waiting for checks to finish 2025/04/16 04:29:59 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-biqaqid5vuba': Waiting for transfers to finish 2025/04/16 04:29:59 DEBUG : Waiting for deletions to finish 2025/04/16 04:29:59 INFO : There was nothing to transfer --- PASS: TestSyncIgnoreCase (3.02s) === RUN TestFixCase run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-biqaqid5vuba'", Local "Local file system at /tmp/rclone2020710954", Modify Window "1ms" sync_test.go:2635: Skipping test as local or remote are case-sensitive --- SKIP: TestFixCase (0.44s) === RUN TestMaxTransfer === RUN TestMaxTransfer/Hard run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-biqaqid5vuba'", Local "Local file system at /tmp/rclone2020710954", 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-biqaqid5vuba'", Local "Local file system at /tmp/rclone2020710954", 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-biqaqid5vuba'", Local "Local file system at /tmp/rclone2020710954", Modify Window "1ms" sync_test.go:2674: This test only runs on local --- PASS: TestMaxTransfer (1.32s) --- SKIP: TestMaxTransfer/Hard (0.45s) --- SKIP: TestMaxTransfer/Soft (0.45s) --- SKIP: TestMaxTransfer/Cautious (0.42s) === RUN TestSyncConcurrentDelete run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-biqaqid5vuba'", Local "Local file system at /tmp/rclone2020710954", Modify Window "1ms" 2025/04/16 04:30:03 DEBUG : both0: md5 = 960e71da3bc78d6bba7931ef43ffccea OK 2025/04/16 04:30:05 DEBUG : only0: md5 = 1737dc073bfe8e504052fdada919ad01 OK 2025/04/16 04:30:06 DEBUG : both1: md5 = 50e44657178af47b67dfe7015967110c OK 2025/04/16 04:30:08 DEBUG : only1: md5 = 279f1664adc7286f082b58b88b0cf171 OK 2025/04/16 04:30:09 DEBUG : both2: md5 = ad0b0486384570b5d5910cdd24a61835 OK 2025/04/16 04:30:11 DEBUG : only2: md5 = 01765b541c951c72fbedf344ff9c30ac OK 2025/04/16 04:30:12 DEBUG : both3: md5 = 1d3a186a1c127c63c3aef9ecf90cfb1d OK 2025/04/16 04:30:13 DEBUG : only3: md5 = c8d9c0322eb316785bbbbf8e5c67c5f1 OK 2025/04/16 04:30:15 DEBUG : both4: md5 = 5fbafa63d2a33d15da894e7256ea5f91 OK 2025/04/16 04:30:16 DEBUG : only4: md5 = 1ee1cf90ced1ccd5bf7a5d101fb529ce OK 2025/04/16 04:30:17 DEBUG : both5: md5 = 1c20d7d8b20fd94b3a898100e708052c OK 2025/04/16 04:30:19 DEBUG : only5: md5 = d9b99f6ce68b299f310e466534ef7a48 OK 2025/04/16 04:30:20 DEBUG : both6: md5 = 19f8aae08441d727dec1a92e38fdb456 OK 2025/04/16 04:30:22 DEBUG : only6: md5 = b9ce960bbfa445b5341caffc06d704d4 OK 2025/04/16 04:30:23 DEBUG : both7: md5 = 5683b711f533dc6266d240a1c086c7b3 OK 2025/04/16 04:30:24 DEBUG : only7: md5 = 3b1366bbb9e4c54e6558bbea23ce433c OK 2025/04/16 04:30:26 DEBUG : both8: md5 = 3d08fcc04ed483bb5e2feca2a5cda8ca OK 2025/04/16 04:30:27 DEBUG : only8: md5 = ed6417afb9269593f5d90b86622ae06d OK 2025/04/16 04:30:29 DEBUG : both9: md5 = b4bc9ff476c16c2063a39e35ba495229 OK 2025/04/16 04:30:30 DEBUG : only9: md5 = 0db0b862894db56c5b21ff1121725a5f OK 2025/04/16 04:30:31 DEBUG : both10: md5 = 830771abaf3c2890332883424fc291a5 OK 2025/04/16 04:30:33 DEBUG : only10: md5 = b4813a312b371caeed0ee0d4c847498b OK 2025/04/16 04:30:34 DEBUG : both11: md5 = c0be06a0aa65e5975c072d0ffba0b0e7 OK 2025/04/16 04:30:36 DEBUG : only11: md5 = 01db36a93797b15a9b8349cffea176b3 OK 2025/04/16 04:30:37 DEBUG : both12: md5 = 8eb9f9bc893fa265557e981e8e26c2fa OK 2025/04/16 04:30:38 DEBUG : only12: md5 = 3b0b05e3cdaa87b9eb2645c614da499d OK 2025/04/16 04:30:40 DEBUG : both13: md5 = b8e726bbd1760c0b9c5872af19ff703a OK 2025/04/16 04:30:41 DEBUG : only13: md5 = e26127cb45282c4b05e34824a6a288a2 OK 2025/04/16 04:30:43 DEBUG : both14: md5 = 5443d11a02b5302a9c066937810cc09d OK 2025/04/16 04:30:44 DEBUG : only14: md5 = 74c45d0986fe361d602915fed1ed1f09 OK 2025/04/16 04:30:45 DEBUG : both15: md5 = a419cc7d9358f08d10f9cc0eeb13bf7d OK 2025/04/16 04:30:47 DEBUG : only15: md5 = c4a58685483072de50b001625910fe42 OK 2025/04/16 04:30:48 DEBUG : both16: md5 = e28cb981f904041f84efa11f7a96abc2 OK 2025/04/16 04:30:50 DEBUG : only16: md5 = 4cfb0906981408f84742a0a6c8e786bd OK 2025/04/16 04:30:51 DEBUG : both17: md5 = aab4fe6a7595839bc9fd4b09daacec08 OK 2025/04/16 04:30:52 DEBUG : only17: md5 = 09bfc5eafd6b052c45a294a5cd971b29 OK 2025/04/16 04:30:54 DEBUG : both18: md5 = a588856b6d7e6f867e95cbd95e031bb0 OK 2025/04/16 04:30:55 DEBUG : only18: md5 = 5181288df7d15b8c860888f7b56d64b8 OK 2025/04/16 04:30:57 DEBUG : both19: md5 = 530a2d4888c7957e0ea838c7aedbad60 OK 2025/04/16 04:30:58 DEBUG : only19: md5 = 6905e3e10d39c2199c9cf072760d3a04 OK 2025/04/16 04:30:59 DEBUG : both0: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/16 04:30:59 DEBUG : both1: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/16 04:30:59 DEBUG : both11: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/16 04:30:59 DEBUG : both10: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/16 04:30:59 DEBUG : both0: Unchanged skipping 2025/04/16 04:30:59 DEBUG : both12: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/16 04:30:59 DEBUG : both12: Unchanged skipping 2025/04/16 04:30:59 DEBUG : both13: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/16 04:30:59 DEBUG : both13: Unchanged skipping 2025/04/16 04:30:59 DEBUG : both14: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/16 04:30:59 DEBUG : both14: Unchanged skipping 2025/04/16 04:30:59 DEBUG : both15: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/16 04:30:59 DEBUG : both15: Unchanged skipping 2025/04/16 04:30:59 DEBUG : both16: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/16 04:30:59 DEBUG : both16: Unchanged skipping 2025/04/16 04:30:59 DEBUG : both17: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/16 04:30:59 DEBUG : both17: Unchanged skipping 2025/04/16 04:30:59 DEBUG : both18: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/16 04:30:59 DEBUG : both18: Unchanged skipping 2025/04/16 04:30:59 DEBUG : both19: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/16 04:30:59 DEBUG : both19: Unchanged skipping 2025/04/16 04:30:59 DEBUG : both2: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/16 04:30:59 DEBUG : both2: Unchanged skipping 2025/04/16 04:30:59 DEBUG : both3: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/16 04:30:59 DEBUG : both3: Unchanged skipping 2025/04/16 04:30:59 DEBUG : both4: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/16 04:30:59 DEBUG : both4: Unchanged skipping 2025/04/16 04:30:59 DEBUG : both5: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/16 04:30:59 DEBUG : both5: Unchanged skipping 2025/04/16 04:30:59 DEBUG : both6: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/16 04:30:59 DEBUG : both6: Unchanged skipping 2025/04/16 04:30:59 DEBUG : both7: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/16 04:30:59 DEBUG : both7: Unchanged skipping 2025/04/16 04:30:59 DEBUG : both8: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/16 04:30:59 DEBUG : both8: Unchanged skipping 2025/04/16 04:30:59 DEBUG : both9: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/16 04:30:59 DEBUG : both9: Unchanged skipping 2025/04/16 04:30:59 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-biqaqid5vuba': Waiting for checks to finish 2025/04/16 04:30:59 DEBUG : both1: Unchanged skipping 2025/04/16 04:30:59 DEBUG : both11: Unchanged skipping 2025/04/16 04:30:59 DEBUG : both10: Unchanged skipping 2025/04/16 04:30:59 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-biqaqid5vuba': Waiting for transfers to finish 2025/04/16 04:30:59 DEBUG : Waiting for deletions to finish 2025/04/16 04:30:59 INFO : only4: Deleted 2025/04/16 04:30:59 INFO : only13: Deleted 2025/04/16 04:30:59 INFO : only11: Deleted 2025/04/16 04:30:59 INFO : only7: Deleted 2025/04/16 04:31:00 INFO : only15: Deleted 2025/04/16 04:31:00 INFO : only3: Deleted 2025/04/16 04:31:00 INFO : only16: Deleted 2025/04/16 04:31:00 INFO : only19: Deleted 2025/04/16 04:31:00 INFO : only18: Deleted 2025/04/16 04:31:00 INFO : only1: Deleted 2025/04/16 04:31:00 INFO : only2: Deleted 2025/04/16 04:31:00 INFO : only8: Deleted 2025/04/16 04:31:00 INFO : only0: Deleted 2025/04/16 04:31:01 INFO : only12: Deleted 2025/04/16 04:31:01 INFO : only14: Deleted 2025/04/16 04:31:01 INFO : only17: Deleted 2025/04/16 04:31:01 INFO : only5: Deleted 2025/04/16 04:31:01 INFO : only9: Deleted 2025/04/16 04:31:01 INFO : only10: Deleted 2025/04/16 04:31:01 INFO : only6: Deleted 2025/04/16 04:31:01 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-biqaqid5vuba'", Local "Local file system at /tmp/rclone2020710954", Modify Window "1ms" --- PASS: TestSyncConcurrentDelete (69.54s) === RUN TestSyncConcurrentTruncate run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-biqaqid5vuba'", Local "Local file system at /tmp/rclone2020710954", Modify Window "1ms" 2025/04/16 04:31:13 DEBUG : both0: md5 = 74af251f96c0a4015e700d381809b2ca OK 2025/04/16 04:31:14 DEBUG : only0: md5 = fccbea4e069aafb2740470d06bb4fcd8 OK 2025/04/16 04:31:16 DEBUG : both1: md5 = b8024fd59efbdbcb970cfbf1e4701b66 OK 2025/04/16 04:31:17 DEBUG : only1: md5 = 7ec2b19057077e8ab73c9d134b534ab3 OK 2025/04/16 04:31:18 DEBUG : both2: md5 = cfae0908f4dda7a43b5e2ac9bfc371f6 OK 2025/04/16 04:31:20 DEBUG : only2: md5 = 94412a83cbf6d39844edaf05a77e023d OK 2025/04/16 04:31:21 DEBUG : both3: md5 = 9e6d09de7c9fba8f4a5ff01fdf2ab67f OK 2025/04/16 04:31:22 DEBUG : only3: md5 = 214c9572ca07fa8773de20d8c01336dc OK 2025/04/16 04:31:24 DEBUG : both4: md5 = 38f5a60e491b6883b436f77b656a8269 OK 2025/04/16 04:31:25 DEBUG : only4: md5 = 216bd943c3436c9b6fc44669349eaf9e OK 2025/04/16 04:31:27 DEBUG : both5: md5 = 078e5d72579ada0410c1274698c79afc OK 2025/04/16 04:31:28 DEBUG : only5: md5 = 22568466ad72af1e97e64d63265a820b OK 2025/04/16 04:31:29 DEBUG : both6: md5 = 33287b8678a5343cd3767638f4feb937 OK 2025/04/16 04:31:31 DEBUG : only6: md5 = 740fb62274193059be57b8ff1398e612 OK 2025/04/16 04:31:32 DEBUG : both7: md5 = 06b7585df70dbeb510c7d7c96ba3b66a OK 2025/04/16 04:31:33 DEBUG : only7: md5 = b365bd01cbc162166c52a5c1a9b7171c OK 2025/04/16 04:31:35 DEBUG : both8: md5 = db16e160c7919848ae4d603c23cf86ad OK 2025/04/16 04:31:36 DEBUG : only8: md5 = 6725ad65d87074138a83777bec567376 OK 2025/04/16 04:31:37 DEBUG : both9: md5 = 432806b264986f2643c31a3479c07cdb OK 2025/04/16 04:31:39 DEBUG : only9: md5 = 2891e72f77f51dc3ac18f134d470616d OK 2025/04/16 04:31:40 DEBUG : both10: md5 = 00a5e8a0e08d45d3a6ccf65976404bf2 OK 2025/04/16 04:31:41 DEBUG : only10: md5 = 2ace554927b84c36c29463835e077b46 OK 2025/04/16 04:31:43 DEBUG : both11: md5 = 32dd17d489eba2ee93ebf5cd456acfc1 OK 2025/04/16 04:31:44 DEBUG : only11: md5 = ab795254c3383c758b5921b776472790 OK 2025/04/16 04:31:45 DEBUG : both12: md5 = 097c095e0631b3a6a1bf45a92af4e716 OK 2025/04/16 04:31:46 DEBUG : only12: md5 = c5c4e9ca65c45a7a284005c9df09922f OK 2025/04/16 04:31:48 DEBUG : both13: md5 = 3e5fa5bc9c3fbc9cd112d20ca7022b3f OK 2025/04/16 04:31:49 DEBUG : only13: md5 = a33969b92b733f69655c60943721a13c OK 2025/04/16 04:31:51 DEBUG : both14: md5 = b15621e4776f612f60af19f993523215 OK 2025/04/16 04:31:52 DEBUG : only14: md5 = ef81441ec4f0bd16df408ca32b57eaa9 OK 2025/04/16 04:31:53 DEBUG : both15: md5 = a559727c5a75432267b989c76555f0e8 OK 2025/04/16 04:31:55 DEBUG : only15: md5 = cdd4eeab7c1bbca857c5f0b2a45836a4 OK 2025/04/16 04:31:56 DEBUG : both16: md5 = f057ff0ab3807b7a56c58ec1cc2e95f5 OK 2025/04/16 04:31:58 DEBUG : only16: md5 = c5c0e7456730516243adb54390170c5b OK 2025/04/16 04:31:59 DEBUG : both17: md5 = 7459d8dc1a7fb765eadfaa8e6c69b01a OK 2025/04/16 04:32:01 DEBUG : only17: md5 = 905d5aa29cc2f52573a1aba7ca47ccc3 OK 2025/04/16 04:32:02 DEBUG : both18: md5 = a495cdfac90a3b1fed8b6e948750aee5 OK 2025/04/16 04:32:04 DEBUG : only18: md5 = 8fe8599e9e16ddbe7f3e8ef9267ba8c1 OK 2025/04/16 04:32:05 DEBUG : both19: md5 = bc71d52200c356310bd93c2db5b73aa1 OK 2025/04/16 04:32:06 DEBUG : only19: md5 = 64a9496fe54e6ba04aba8f7240706ad2 OK 2025/04/16 04:32:07 DEBUG : both0: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/16 04:32:07 DEBUG : both1: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/16 04:32:07 DEBUG : both10: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/16 04:32:07 DEBUG : both11: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/16 04:32:07 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-biqaqid5vuba': Waiting for checks to finish 2025/04/16 04:32:07 DEBUG : both0: Unchanged skipping 2025/04/16 04:32:07 DEBUG : both12: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/16 04:32:07 DEBUG : both1: Unchanged skipping 2025/04/16 04:32:07 DEBUG : both13: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/16 04:32:07 DEBUG : both13: Unchanged skipping 2025/04/16 04:32:07 DEBUG : both14: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/16 04:32:07 DEBUG : both10: Unchanged skipping 2025/04/16 04:32:07 DEBUG : both15: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/16 04:32:07 DEBUG : both15: Unchanged skipping 2025/04/16 04:32:07 DEBUG : both16: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/16 04:32:07 DEBUG : both11: Unchanged skipping 2025/04/16 04:32:07 DEBUG : both17: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/16 04:32:07 DEBUG : both12: Unchanged skipping 2025/04/16 04:32:07 DEBUG : both18: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/16 04:32:07 DEBUG : both14: Unchanged skipping 2025/04/16 04:32:07 DEBUG : both19: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/16 04:32:07 DEBUG : both19: Unchanged skipping 2025/04/16 04:32:07 DEBUG : both2: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/16 04:32:07 DEBUG : both2: Unchanged skipping 2025/04/16 04:32:07 DEBUG : both3: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/16 04:32:07 DEBUG : both3: Unchanged skipping 2025/04/16 04:32:07 DEBUG : both4: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/16 04:32:07 DEBUG : both16: Unchanged skipping 2025/04/16 04:32:07 DEBUG : both5: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/16 04:32:07 DEBUG : both17: Unchanged skipping 2025/04/16 04:32:07 DEBUG : both6: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/16 04:32:07 DEBUG : both6: Unchanged skipping 2025/04/16 04:32:07 DEBUG : both7: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/16 04:32:07 DEBUG : both7: Unchanged skipping 2025/04/16 04:32:07 DEBUG : both8: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/16 04:32:07 DEBUG : both18: Unchanged skipping 2025/04/16 04:32:07 DEBUG : both9: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/16 04:32:07 DEBUG : both4: Unchanged skipping 2025/04/16 04:32:07 DEBUG : only0: Sizes differ (src 0 vs dst 6) 2025/04/16 04:32:07 DEBUG : only1: Sizes differ (src 0 vs dst 6) 2025/04/16 04:32:07 DEBUG : both5: Unchanged skipping 2025/04/16 04:32:07 DEBUG : only10: Sizes differ (src 0 vs dst 6) 2025/04/16 04:32:07 DEBUG : only11: Sizes differ (src 0 vs dst 6) 2025/04/16 04:32:07 DEBUG : only12: Sizes differ (src 0 vs dst 6) 2025/04/16 04:32:07 DEBUG : both8: Unchanged skipping 2025/04/16 04:32:07 DEBUG : only13: Sizes differ (src 0 vs dst 6) 2025/04/16 04:32:07 DEBUG : only14: Sizes differ (src 0 vs dst 6) 2025/04/16 04:32:07 DEBUG : both9: Unchanged skipping 2025/04/16 04:32:07 DEBUG : only15: Sizes differ (src 0 vs dst 6) 2025/04/16 04:32:07 DEBUG : only16: Sizes differ (src 0 vs dst 6) 2025/04/16 04:32:07 DEBUG : only17: Sizes differ (src 0 vs dst 6) 2025/04/16 04:32:07 DEBUG : only18: Sizes differ (src 0 vs dst 6) 2025/04/16 04:32:07 DEBUG : only19: Sizes differ (src 0 vs dst 6) 2025/04/16 04:32:07 DEBUG : only2: Sizes differ (src 0 vs dst 6) 2025/04/16 04:32:07 DEBUG : only3: Sizes differ (src 0 vs dst 6) 2025/04/16 04:32:07 DEBUG : only4: Sizes differ (src 0 vs dst 6) 2025/04/16 04:32:07 DEBUG : only5: Sizes differ (src 0 vs dst 6) 2025/04/16 04:32:07 DEBUG : only6: Sizes differ (src 0 vs dst 6) 2025/04/16 04:32:07 DEBUG : only7: Sizes differ (src 0 vs dst 6) 2025/04/16 04:32:07 DEBUG : only8: Sizes differ (src 0 vs dst 6) 2025/04/16 04:32:07 DEBUG : only9: Sizes differ (src 0 vs dst 6) 2025/04/16 04:32:07 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-biqaqid5vuba': Waiting for transfers to finish 2025/04/16 04:32:08 DEBUG : only13: md5 = 19a1b6c672ef62fd058d4a3f81005e18 OK 2025/04/16 04:32:08 INFO : only13: Copied (replaced existing) 2025/04/16 04:32:08 DEBUG : only0: md5 = eaa10fce31e71cb124d090f771fe2af9 OK 2025/04/16 04:32:08 INFO : only0: Copied (replaced existing) 2025/04/16 04:32:08 DEBUG : only11: md5 = 8c86197597eb1333b353a68390d443ac OK 2025/04/16 04:32:08 INFO : only11: Copied (replaced existing) 2025/04/16 04:32:08 DEBUG : only10: md5 = 15941d335565339390946324e41dd0d1 OK 2025/04/16 04:32:08 INFO : only10: Copied (replaced existing) 2025/04/16 04:32:09 DEBUG : only16: md5 = f0b0ae5fb7f1a403eddbaaab91cf2c6b OK 2025/04/16 04:32:09 INFO : only16: Copied (replaced existing) 2025/04/16 04:32:09 DEBUG : only15: md5 = 8770f2e0f8b41264813f7d53ed4d87d7 OK 2025/04/16 04:32:09 INFO : only15: Copied (replaced existing) 2025/04/16 04:32:09 DEBUG : only18: md5 = 50d741760faaaef5abf89bdb05b9270a OK 2025/04/16 04:32:09 INFO : only18: Copied (replaced existing) 2025/04/16 04:32:09 DEBUG : only17: md5 = 3fcd2d2ff128de1844c488774280d490 OK 2025/04/16 04:32:09 INFO : only17: Copied (replaced existing) 2025/04/16 04:32:10 DEBUG : only19: md5 = fdf763ac6e588b52618e1120c65cdd6d OK 2025/04/16 04:32:10 INFO : only19: Copied (replaced existing) 2025/04/16 04:32:10 DEBUG : only3: md5 = 2d1685af9cfec62b1715a6e4076fb1b0 OK 2025/04/16 04:32:10 INFO : only3: Copied (replaced existing) 2025/04/16 04:32:10 DEBUG : only2: md5 = 9f76b7ea2df84f0b8bf3e693f3ba5db5 OK 2025/04/16 04:32:10 INFO : only2: Copied (replaced existing) 2025/04/16 04:32:11 DEBUG : only12: md5 = d6bf9ae0eedfbcdfd02ce447afd2d336 OK 2025/04/16 04:32:11 INFO : only12: Copied (replaced existing) 2025/04/16 04:32:11 DEBUG : only1: md5 = 7f4190b7dd24076bf3f383b1daa349e5 OK 2025/04/16 04:32:11 INFO : only1: Copied (replaced existing) 2025/04/16 04:32:11 DEBUG : only7: md5 = 854f847c89839f6b35d222bbc43d5bf0 OK 2025/04/16 04:32:11 INFO : only7: Copied (replaced existing) 2025/04/16 04:32:12 DEBUG : only4: md5 = 4007fe5edca95123c3bf6162abeda56e OK 2025/04/16 04:32:12 INFO : only4: Copied (replaced existing) 2025/04/16 04:32:12 DEBUG : only8: md5 = 8a3a38b67bbc185357e85b2458ecbfa4 OK 2025/04/16 04:32:12 INFO : only8: Copied (replaced existing) 2025/04/16 04:32:12 DEBUG : only5: md5 = a59b1070b73d3a7da43fa4458a0cd89f OK 2025/04/16 04:32:12 INFO : only5: Copied (replaced existing) 2025/04/16 04:32:13 DEBUG : only14: md5 = de96c7828f26e484f91a6ecfe5e5c1bb OK 2025/04/16 04:32:13 INFO : only14: Copied (replaced existing) 2025/04/16 04:32:13 DEBUG : only6: md5 = abe0731f2263ccae9cfbe4884153c2c7 OK 2025/04/16 04:32:13 INFO : only6: Copied (replaced existing) 2025/04/16 04:32:13 DEBUG : only9: md5 = cb9197e9e8945001f39cf43c04d9f503 OK 2025/04/16 04:32:13 INFO : only9: Copied (replaced existing) 2025/04/16 04:32:13 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-biqaqid5vuba'", Local "Local file system at /tmp/rclone2020710954", Modify Window "1ms" --- PASS: TestSyncConcurrentTruncate (80.79s) === RUN TestSyncReplaceDirModTime run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-biqaqid5vuba'", Local "Local file system at /tmp/rclone2020710954", Modify Window "1ms" 2025/04/16 04:32:32 DEBUG : empty_dir: Making directory with metadata 2025/04/16 04:32:32 INFO : empty_dir: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2025/04/16 04:32:32 DEBUG : empty_on_remote: Making directory with metadata 2025/04/16 04:32:32 INFO : empty_on_remote: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2025/04/16 04:32:32 DEBUG : empty_on_remote: Making directory with metadata 2025/04/16 04:32:33 INFO : empty_on_remote: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-biqaqid5vuba'", Local "Local file system at /tmp/rclone2020710954", Modify Window "1ms" 2025/04/16 04:32:38 INFO : test_dir1: Set directory modification time (using DirSetModTime) 2025/04/16 04:32:38 INFO : test_dir2: Set directory modification time (using DirSetModTime) 2025/04/16 04:32:38 INFO : test_dir2/sub_dir: Set directory modification time (using DirSetModTime) 2025/04/16 04:32:38 INFO : empty_on_remote: Set directory modification time (using DirSetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-biqaqid5vuba'", Local "Local file system at /tmp/rclone2020710954", Modify Window "1ms" 2025/04/16 04:32:46 DEBUG : heqj02jg0dcqlem7gl0500bvp0/24g2k8bseitblkmqnie1ibl2s8: Rmdir: contains trashed file: "633fmaa0qic3kv3cladnu11pto" 2025/04/16 04:32:47 DEBUG : heqj02jg0dcqlem7gl0500bvp0: Rmdir: contains trashed file: "24g2k8bseitblkmqnie1ibl2s8" 2025/04/16 04:32:47 DEBUG : gq68srrpl0nnf394bgf7dbu9kc: Rmdir: contains trashed file: "d26uovf0miqhd1mu3c9jbseq00" --- PASS: TestSyncReplaceDirModTime (17.44s) === RUN TestSyncReplaceDirModTimeWithEmptyDirs run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-biqaqid5vuba'", Local "Local file system at /tmp/rclone2020710954", Modify Window "1ms" 2025/04/16 04:32:50 DEBUG : empty_dir: Making directory with metadata 2025/04/16 04:32:50 INFO : empty_dir: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2025/04/16 04:32:50 DEBUG : empty_on_remote: Making directory with metadata 2025/04/16 04:32:50 INFO : empty_on_remote: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2025/04/16 04:32:50 DEBUG : empty_on_remote: Making directory with metadata 2025/04/16 04:32:51 INFO : empty_on_remote: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-biqaqid5vuba'", Local "Local file system at /tmp/rclone2020710954", Modify Window "1ms" 2025/04/16 04:32:56 INFO : test_dir1: Set directory modification time (using DirSetModTime) 2025/04/16 04:32:56 INFO : test_dir2: Set directory modification time (using DirSetModTime) 2025/04/16 04:32:56 INFO : test_dir2/sub_dir: Set directory modification time (using DirSetModTime) 2025/04/16 04:32:56 INFO : empty_on_remote: Set directory modification time (using DirSetModTime) 2025/04/16 04:32:56 INFO : empty_dir: Set directory modification time (using DirSetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-biqaqid5vuba'", Local "Local file system at /tmp/rclone2020710954", Modify Window "1ms" 2025/04/16 04:33:03 DEBUG : heqj02jg0dcqlem7gl0500bvp0/24g2k8bseitblkmqnie1ibl2s8: Rmdir: contains trashed file: "633fmaa0qic3kv3cladnu11pto" 2025/04/16 04:33:04 DEBUG : heqj02jg0dcqlem7gl0500bvp0: Rmdir: contains trashed file: "24g2k8bseitblkmqnie1ibl2s8" 2025/04/16 04:33:05 DEBUG : gq68srrpl0nnf394bgf7dbu9kc: Rmdir: contains trashed file: "d26uovf0miqhd1mu3c9jbseq00" --- PASS: TestSyncReplaceDirModTimeWithEmptyDirs (17.80s) === RUN TestNothingToTransferWithEmptyDirs run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-biqaqid5vuba'", Local "Local file system at /tmp/rclone2020710954", Modify Window "1ms" 2025/04/16 04:33:08 INFO : sub dir: Set directory modification time (using DirSetModTime) 2025/04/16 04:33:08 DEBUG : sub dir: Making directory with metadata 2025/04/16 04:33:08 INFO : sub dir: Made directory with metadata (mtime=2011-12-30T12:59:59Z) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-biqaqid5vuba'", Local "Local file system at /tmp/rclone2020710954", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-biqaqid5vuba'", Local "Local file system at /tmp/rclone2020710954", Modify Window "1ms" 2025/04/16 04:33:26 INFO : sub dir2: Set directory modification time (using DirSetModTime) 2025/04/16 04:33:27 INFO : sub dir2: Set directory modification time (using DirSetModTime) 2025/04/16 04:33:27 INFO : sub dirEmpty/sub dirEmpty2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2025/04/16 04:33:27 INFO : sub dirEmpty: Set directory modification time (using DirSetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-biqaqid5vuba'", Local "Local file system at /tmp/rclone2020710954", Modify Window "1ms" 2025/04/16 04:33:41 DEBUG : gcsdkq814sbtppue42dpsbg8ug: Rmdir: contains trashed file: "sjuo65gk5q3r1199jselk9k9o0" 2025/04/16 04:33:41 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/37qp6d1gohacv723ij3brofbu8/i24n0ln37pa2hv8pctddeuh73o: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" 2025/04/16 04:33:42 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/37qp6d1gohacv723ij3brofbu8: Rmdir: contains trashed file: "i24n0ln37pa2hv8pctddeuh73o" 2025/04/16 04:33:43 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "37qp6d1gohacv723ij3brofbu8" 2025/04/16 04:33:44 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak" 2025/04/16 04:33:44 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak" 2025/04/16 04:33:45 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak" 2025/04/16 04:33:46 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak" 2025/04/16 04:33:46 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/4r13oncfa2rsrr82oqhsqv24ns: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" 2025/04/16 04:33:47 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc: Rmdir: contains trashed file: "4r13oncfa2rsrr82oqhsqv24ns" 2025/04/16 04:33:47 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak" 2025/04/16 04:33:48 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestNothingToTransferWithEmptyDirs (42.19s) === RUN TestNothingToTransferWithoutEmptyDirs run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-biqaqid5vuba'", Local "Local file system at /tmp/rclone2020710954", Modify Window "1ms" 2025/04/16 04:33:50 INFO : sub dir: Set directory modification time (using DirSetModTime) 2025/04/16 04:33:50 DEBUG : sub dir: Making directory with metadata 2025/04/16 04:33:51 INFO : sub dir: Made directory with metadata (mtime=2011-12-30T12:59:59Z) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-biqaqid5vuba'", Local "Local file system at /tmp/rclone2020710954", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-biqaqid5vuba'", Local "Local file system at /tmp/rclone2020710954", Modify Window "1ms" 2025/04/16 04:34:12 INFO : sub dir2: Set directory modification time (using DirSetModTime) 2025/04/16 04:34:13 INFO : sub dir2: Set directory modification time (using DirSetModTime) 2025/04/16 04:34:13 INFO : sub dirEmpty/sub dirEmpty2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2025/04/16 04:34:13 INFO : sub dirEmpty: Set directory modification time (using DirSetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-biqaqid5vuba'", Local "Local file system at /tmp/rclone2020710954", Modify Window "1ms" 2025/04/16 04:34:26 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/37qp6d1gohacv723ij3brofbu8/i24n0ln37pa2hv8pctddeuh73o: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" 2025/04/16 04:34:27 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/37qp6d1gohacv723ij3brofbu8: Rmdir: contains trashed file: "i24n0ln37pa2hv8pctddeuh73o" 2025/04/16 04:34:28 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "37qp6d1gohacv723ij3brofbu8" 2025/04/16 04:34:28 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak" 2025/04/16 04:34:29 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak" 2025/04/16 04:34:30 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak" 2025/04/16 04:34:30 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak" 2025/04/16 04:34:31 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/4r13oncfa2rsrr82oqhsqv24ns: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" 2025/04/16 04:34:32 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc: Rmdir: contains trashed file: "4r13oncfa2rsrr82oqhsqv24ns" 2025/04/16 04:34:32 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak" 2025/04/16 04:34:33 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestNothingToTransferWithoutEmptyDirs (44.97s) PASS 2025/04/16 04:34:35 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-biqaqid5vuba': Purge remote "./sync.test -test.v -test.timeout 1h0m0s -remote TestCryptDrive: -verbose -fast-list" - Finished OK in 15m46.728227792s (try 1/5)