"./sync.test -test.v -test.timeout 1h0m0s -remote TestCryptDrive: -verbose" - Starting (try 1/5) 2025/05/01 06:20:40 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-zedurer9kufu" 2025/05/01 06:20:40 DEBUG : Using config file from "/home/rclone/.rclone.conf" 2025/05/01 06:20:40 DEBUG : Creating backend with remote "TestDrive:crypt/8qbvuohkaa3egsv9bvujjbl2eclmttfbdc6hgn8m0s7jo9antms0" 2025/05/01 06:20:41 DEBUG : Creating backend with remote "/tmp/rclone1815725417" === 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-zedurer9kufu'", Local "Local file system at /tmp/rclone1815725417", Modify Window "1ms" 2025/05/01 06:20:42 DEBUG : Added delayed dir = "sub dir", newDst= 2025/05/01 06:20:42 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2025/05/01 06:20:42 NOTICE: sub dir/hello world: Skipped copy as --dry-run is set (size 11) 2025/05/01 06:20:42 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zedurer9kufu': Waiting for checks to finish 2025/05/01 06:20:42 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zedurer9kufu': Waiting for transfers to finish 2025/05/01 06:20:42 NOTICE: sub dir: Skipped set directory modification time as --dry-run is set run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zedurer9kufu'", Local "Local file system at /tmp/rclone1815725417", Modify Window "1ms" --- PASS: TestCopyWithDryRun (2.00s) === RUN TestCopy run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zedurer9kufu'", Local "Local file system at /tmp/rclone1815725417", Modify Window "1ms" 2025/05/01 06:20:43 INFO : sub dir: Set directory modification time (using DirSetModTime) 2025/05/01 06:20:43 DEBUG : Added delayed dir = "sub dir", newDst= 2025/05/01 06:20:43 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2025/05/01 06:20:43 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zedurer9kufu': Waiting for checks to finish 2025/05/01 06:20:43 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zedurer9kufu': Waiting for transfers to finish 2025/05/01 06:20:45 DEBUG : sub dir/hello world: md5 = b365e050d321fb1c93a0566301f68a49 OK 2025/05/01 06:20:45 INFO : sub dir/hello world: Copied (new) 2025/05/01 06:20:46 INFO : sub dir: Set directory modification time (using DirSetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zedurer9kufu'", Local "Local file system at /tmp/rclone1815725417", Modify Window "1ms" 2025/05/01 06:20:48 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestCopy (6.16s) === RUN TestCopyMetadata run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zedurer9kufu'", Local "Local file system at /tmp/rclone1815725417", Modify Window "1ms" 2025/05/01 06:20:49 DEBUG : metadata sub dir: Making directory with metadata 2025/05/01 06:20:49 INFO : metadata sub dir: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2025/05/01 06:20:49 DEBUG : empty metadata sub dir: Making directory with metadata 2025/05/01 06:20:49 INFO : empty metadata sub dir: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2025/05/01 06:20:49 DEBUG : Local file system at /tmp/rclone1815725417: File to upload is small (21 bytes), uploading instead of streaming 2025/05/01 06:20:49 DEBUG : metadata sub dir/hello metadata world: md5 = baa7a013449dbba2b1ed02b5cfb4e1a2 OK 2025/05/01 06:20:49 DEBUG : metadata sub dir/hello metadata world: Size and md5 of src and dst objects identical 2025/05/01 06:20:49 INFO : metadata sub dir: Set directory modification time (using DirSetModTime) 2025/05/01 06:20:49 DEBUG : Google drive root 'crypt/8qbvuohkaa3egsv9bvujjbl2eclmttfbdc6hgn8m0s7jo9antms0': Skipping btime metadata as can't update it on an existing file: 2025-05-01T06:20:49.537024415Z 2025/05/01 06:20:50 INFO : empty metadata sub dir: Updated directory metadata 2025/05/01 06:20:50 DEBUG : Google drive root 'crypt/8qbvuohkaa3egsv9bvujjbl2eclmttfbdc6hgn8m0s7jo9antms0': Skipping btime metadata as can't update it on an existing file: 2025-05-01T06:20:49.537024415Z 2025/05/01 06:20:51 INFO : metadata sub dir: Updated directory metadata 2025/05/01 06:20:51 DEBUG : metadata sub dir/hello metadata world: Need to transfer - File not found at Destination 2025/05/01 06:20:51 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zedurer9kufu': Waiting for checks to finish 2025/05/01 06:20:51 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zedurer9kufu': Waiting for transfers to finish 2025/05/01 06:20:52 DEBUG : metadata sub dir/hello metadata world: md5 = 09f1e689534a7116f0bcfbb738aea194 OK 2025/05/01 06:20:52 INFO : metadata sub dir/hello metadata world: Copied (new) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zedurer9kufu'", Local "Local file system at /tmp/rclone1815725417", Modify Window "1ms" 2025/05/01 06:20:55 DEBUG : fg45q1rm3kh00nmmkk4m6ihmrcnel1p7551kqhjr9bk2gtd2gbf0: Rmdir: contains trashed file: "dmuvulfij81f693ur0f1vvbvq9v6iscp56daas3m51n9li5e3470" --- PASS: TestCopyMetadata (7.38s) === RUN TestCopyMetadataNoEmptyDirs run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zedurer9kufu'", Local "Local file system at /tmp/rclone1815725417", Modify Window "1ms" 2025/05/01 06:20:56 DEBUG : metadata sub dir: Making directory with metadata 2025/05/01 06:20:56 INFO : metadata sub dir: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2025/05/01 06:20:56 DEBUG : empty metadata sub dir: Making directory with metadata 2025/05/01 06:20:56 INFO : empty metadata sub dir: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2025/05/01 06:20:56 DEBUG : Local file system at /tmp/rclone1815725417: File to upload is small (21 bytes), uploading instead of streaming 2025/05/01 06:20:56 DEBUG : metadata sub dir/hello metadata world: md5 = baa7a013449dbba2b1ed02b5cfb4e1a2 OK 2025/05/01 06:20:56 DEBUG : metadata sub dir/hello metadata world: Size and md5 of src and dst objects identical 2025/05/01 06:20:56 INFO : metadata sub dir: Set directory modification time (using DirSetModTime) 2025/05/01 06:20:57 DEBUG : Added delayed dir = "empty metadata sub dir", newDst= 2025/05/01 06:20:57 DEBUG : Added delayed dir = "metadata sub dir", newDst= 2025/05/01 06:20:57 DEBUG : metadata sub dir/hello metadata world: Need to transfer - File not found at Destination 2025/05/01 06:20:57 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zedurer9kufu': Waiting for checks to finish 2025/05/01 06:20:57 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zedurer9kufu': Waiting for transfers to finish 2025/05/01 06:21:00 DEBUG : metadata sub dir/hello metadata world: md5 = bcc1b19d87154e6700bf989ba6bf4cae OK 2025/05/01 06:21:00 INFO : metadata sub dir/hello metadata world: Copied (new) 2025/05/01 06:21:00 DEBUG : Google drive root 'crypt/8qbvuohkaa3egsv9bvujjbl2eclmttfbdc6hgn8m0s7jo9antms0': Skipping btime metadata as can't update it on an existing file: 2025-05-01T06:20:56.913037626Z 2025/05/01 06:21:00 INFO : metadata sub dir: Updated directory metadata run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zedurer9kufu'", Local "Local file system at /tmp/rclone1815725417", Modify Window "1ms" 2025/05/01 06:21:04 DEBUG : fg45q1rm3kh00nmmkk4m6ihmrcnel1p7551kqhjr9bk2gtd2gbf0: Rmdir: contains trashed file: "dmuvulfij81f693ur0f1vvbvq9v6iscp56daas3m51n9li5e3470" --- PASS: TestCopyMetadataNoEmptyDirs (9.02s) === RUN TestCopyMissingDirectory run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zedurer9kufu'", Local "Local file system at /tmp/rclone1815725417", Modify Window "1ms" 2025/05/01 06:21:05 DEBUG : Creating backend with remote "/non-existing" 2025/05/01 06:21:05 DEBUG : Config file has changed externally - reloading 2025/05/01 06:21:06 ERROR : Local file system at /non-existing: error reading source root directory: directory not found 2025/05/01 06:21:06 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zedurer9kufu': Waiting for checks to finish 2025/05/01 06:21:06 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zedurer9kufu': Waiting for transfers to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zedurer9kufu'", Local "Local file system at /tmp/rclone1815725417", Modify Window "1ms" --- PASS: TestCopyMissingDirectory (1.11s) === RUN TestCopyNoTraverse run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zedurer9kufu'", Local "Local file system at /tmp/rclone1815725417", Modify Window "1ms" 2025/05/01 06:21:07 DEBUG : Added delayed dir = "sub dir", newDst= 2025/05/01 06:21:07 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2025/05/01 06:21:07 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zedurer9kufu': Waiting for checks to finish 2025/05/01 06:21:07 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zedurer9kufu': Waiting for transfers to finish 2025/05/01 06:21:09 DEBUG : sub dir/hello world: md5 = 8ad0143182bc95a4e4363e1c44ed1f90 OK 2025/05/01 06:21:09 INFO : sub dir/hello world: Copied (new) 2025/05/01 06:21:10 INFO : sub dir: Set directory modification time (using DirSetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zedurer9kufu'", Local "Local file system at /tmp/rclone1815725417", Modify Window "1ms" 2025/05/01 06:21:11 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestCopyNoTraverse (5.77s) === RUN TestCopyCheckFirst run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zedurer9kufu'", Local "Local file system at /tmp/rclone1815725417", Modify Window "1ms" 2025/05/01 06:21:12 INFO : Encrypted drive 'TestCryptDrive:rclone-test-zedurer9kufu': Running all checks before starting transfers 2025/05/01 06:21:13 DEBUG : Added delayed dir = "sub dir", newDst= 2025/05/01 06:21:13 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2025/05/01 06:21:13 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zedurer9kufu': Waiting for checks to finish 2025/05/01 06:21:13 INFO : Encrypted drive 'TestCryptDrive:rclone-test-zedurer9kufu': Checks finished, now starting transfers 2025/05/01 06:21:13 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zedurer9kufu': Waiting for transfers to finish 2025/05/01 06:21:15 DEBUG : sub dir/hello world: md5 = c41accc4fd9d97afc10f57724f677f07 OK 2025/05/01 06:21:15 INFO : sub dir/hello world: Copied (new) 2025/05/01 06:21:15 INFO : sub dir: Set directory modification time (using DirSetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zedurer9kufu'", Local "Local file system at /tmp/rclone1815725417", Modify Window "1ms" 2025/05/01 06:21:17 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestCopyCheckFirst (5.59s) === RUN TestSyncNoTraverse run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zedurer9kufu'", Local "Local file system at /tmp/rclone1815725417", Modify Window "1ms" 2025/05/01 06:21:18 ERROR : Ignoring --no-traverse with sync 2025/05/01 06:21:18 DEBUG : Added delayed dir = "sub dir", newDst= 2025/05/01 06:21:18 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2025/05/01 06:21:18 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zedurer9kufu': Waiting for checks to finish 2025/05/01 06:21:18 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zedurer9kufu': Waiting for transfers to finish 2025/05/01 06:21:20 DEBUG : sub dir/hello world: md5 = 48f42043f21f30379ece0f6c68a6298a OK 2025/05/01 06:21:20 INFO : sub dir/hello world: Copied (new) 2025/05/01 06:21:20 DEBUG : Waiting for deletions to finish 2025/05/01 06:21:21 INFO : sub dir: Set directory modification time (using DirSetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zedurer9kufu'", Local "Local file system at /tmp/rclone1815725417", Modify Window "1ms" 2025/05/01 06:21:22 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestSyncNoTraverse (5.55s) === RUN TestCopyWithDepth run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zedurer9kufu'", Local "Local file system at /tmp/rclone1815725417", Modify Window "1ms" 2025/05/01 06:21:24 DEBUG : hello world2: Need to transfer - File not found at Destination 2025/05/01 06:21:24 DEBUG : Added delayed dir = "sub dir", newDst= 2025/05/01 06:21:24 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zedurer9kufu': Waiting for checks to finish 2025/05/01 06:21:24 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zedurer9kufu': Waiting for transfers to finish 2025/05/01 06:21:25 DEBUG : hello world2: md5 = f3301ad2b579312f95f5faf99ce8f46f OK 2025/05/01 06:21:25 INFO : hello world2: Copied (new) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zedurer9kufu'", Local "Local file system at /tmp/rclone1815725417", Modify Window "1ms" --- PASS: TestCopyWithDepth (3.17s) === RUN TestCopyWithFilesFrom run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zedurer9kufu'", Local "Local file system at /tmp/rclone1815725417", Modify Window "1ms" 2025/05/01 06:21:27 DEBUG : potato2: Need to transfer - File not found at Destination 2025/05/01 06:21:27 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zedurer9kufu': Waiting for checks to finish 2025/05/01 06:21:27 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zedurer9kufu': Waiting for transfers to finish 2025/05/01 06:21:28 DEBUG : potato2: md5 = dbfbc2fd3c396ea120062cb441dc0cfc OK 2025/05/01 06:21:28 INFO : potato2: Copied (new) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zedurer9kufu'", Local "Local file system at /tmp/rclone1815725417", Modify Window "1ms" --- PASS: TestCopyWithFilesFrom (3.14s) === RUN TestCopyWithFilesFromAndNoTraverse run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zedurer9kufu'", Local "Local file system at /tmp/rclone1815725417", Modify Window "1ms" 2025/05/01 06:21:30 DEBUG : potato2: Need to transfer - File not found at Destination 2025/05/01 06:21:30 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zedurer9kufu': Waiting for checks to finish 2025/05/01 06:21:30 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zedurer9kufu': Waiting for transfers to finish 2025/05/01 06:21:31 DEBUG : potato2: md5 = 06806178596f14d87c60a99a8363a552 OK 2025/05/01 06:21:31 INFO : potato2: Copied (new) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zedurer9kufu'", Local "Local file system at /tmp/rclone1815725417", Modify Window "1ms" --- PASS: TestCopyWithFilesFromAndNoTraverse (3.06s) === RUN TestCopyEmptyDirectories run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zedurer9kufu'", Local "Local file system at /tmp/rclone1815725417", Modify Window "1ms" 2025/05/01 06:21:33 DEBUG : sub dir2/sub sub dir2: Making directory with metadata 2025/05/01 06:21:33 INFO : sub dir2/sub sub dir2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2025/05/01 06:21:33 INFO : sub dir2: Set directory modification time (using DirSetModTime) 2025/05/01 06:21:33 INFO : sub dir: Set directory modification time (using DirSetModTime) 2025/05/01 06:21:33 DEBUG : sub dir: Making directory with metadata 2025/05/01 06:21:34 INFO : sub dir: Made directory with metadata (mtime=2001-02-03T04:05:06.499999999Z) 2025/05/01 06:21:34 DEBUG : sub dir2: Making directory with metadata 2025/05/01 06:21:35 INFO : sub dir2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2025/05/01 06:21:35 DEBUG : sub dir2/sub sub dir2: Making directory with metadata 2025/05/01 06:21:35 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2025/05/01 06:21:35 INFO : sub dir2/sub sub dir2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2025/05/01 06:21:35 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zedurer9kufu': Waiting for checks to finish 2025/05/01 06:21:35 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zedurer9kufu': Waiting for transfers to finish 2025/05/01 06:21:36 DEBUG : sub dir/hello world: md5 = c545b46cb7e66d58a5ff4924a0b5ec46 OK 2025/05/01 06:21:36 INFO : sub dir/hello world: Copied (new) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zedurer9kufu'", Local "Local file system at /tmp/rclone1815725417", Modify Window "1ms" 2025/05/01 06:21:40 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc: Rmdir: contains trashed file: "cv6a9uf28ngrajena8kt5ijjn0" 2025/05/01 06:21:40 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestCopyEmptyDirectories (8.55s) === RUN TestCopyNoEmptyDirectories run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zedurer9kufu'", Local "Local file system at /tmp/rclone1815725417", Modify Window "1ms" 2025/05/01 06:21:41 INFO : sub dir2: Making directory 2025/05/01 06:21:41 DEBUG : sub dir2/sub sub dir2: Making directory with metadata 2025/05/01 06:21:41 INFO : sub dir2/sub sub dir2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2025/05/01 06:21:42 DEBUG : Added delayed dir = "sub dir", newDst= 2025/05/01 06:21:42 DEBUG : Added delayed dir = "sub dir2", newDst= 2025/05/01 06:21:42 DEBUG : Added delayed dir = "sub dir2/sub sub dir2", newDst= 2025/05/01 06:21:42 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2025/05/01 06:21:42 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zedurer9kufu': Waiting for checks to finish 2025/05/01 06:21:42 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zedurer9kufu': Waiting for transfers to finish 2025/05/01 06:21:44 DEBUG : sub dir/hello world: md5 = cdf25ba59856b15338c680dc95ff82d5 OK 2025/05/01 06:21:44 INFO : sub dir/hello world: Copied (new) 2025/05/01 06:21:44 INFO : sub dir: Set directory modification time (using DirSetModTime) 2025/05/01 06:21:46 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestCopyNoEmptyDirectories (5.14s) === RUN TestMoveEmptyDirectories run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zedurer9kufu'", Local "Local file system at /tmp/rclone1815725417", Modify Window "1ms" 2025/05/01 06:21:47 DEBUG : sub dir2: Making directory with metadata 2025/05/01 06:21:47 INFO : sub dir2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2025/05/01 06:21:47 DEBUG : sub dir: Making directory with metadata 2025/05/01 06:21:48 INFO : sub dir: Made directory with metadata (mtime=2025-05-01T06:21:47.029126454Z) 2025/05/01 06:21:48 DEBUG : sub dir2: Making directory with metadata 2025/05/01 06:21:48 INFO : sub dir2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2025/05/01 06:21:48 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2025/05/01 06:21:48 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zedurer9kufu': Waiting for checks to finish 2025/05/01 06:21:48 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zedurer9kufu': Waiting for transfers to finish 2025/05/01 06:21:50 DEBUG : sub dir/hello world: md5 = 71bc18032378741ecb4e66625fa5994b OK 2025/05/01 06:21:50 INFO : sub dir/hello world: Copied (new) 2025/05/01 06:21:50 INFO : sub dir/hello world: Deleted run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zedurer9kufu'", Local "Local file system at /tmp/rclone1815725417", Modify Window "1ms" 2025/05/01 06:21:52 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestMoveEmptyDirectories (6.89s) === RUN TestSyncNoUpdateDirModtime run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zedurer9kufu'", Local "Local file system at /tmp/rclone1815725417", Modify Window "1ms" 2025/05/01 06:21:53 DEBUG : sub dir no update dir modtime: Making directory with metadata 2025/05/01 06:21:53 INFO : sub dir no update dir modtime: Made directory with metadata (mtime=2001-02-03T04:05:06.499999999Z) 2025/05/01 06:21:55 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zedurer9kufu': Waiting for checks to finish 2025/05/01 06:21:55 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zedurer9kufu': Waiting for transfers to finish 2025/05/01 06:21:55 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zedurer9kufu'", Local "Local file system at /tmp/rclone1815725417", Modify Window "1ms" --- PASS: TestSyncNoUpdateDirModtime (3.84s) === RUN TestMoveNoEmptyDirectories run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zedurer9kufu'", Local "Local file system at /tmp/rclone1815725417", Modify Window "1ms" 2025/05/01 06:21:57 INFO : sub dir2: Making directory 2025/05/01 06:21:57 DEBUG : Added delayed dir = "sub dir", newDst= 2025/05/01 06:21:57 DEBUG : Added delayed dir = "sub dir2", newDst= 2025/05/01 06:21:57 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2025/05/01 06:21:57 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zedurer9kufu': Waiting for checks to finish 2025/05/01 06:21:57 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zedurer9kufu': Waiting for transfers to finish 2025/05/01 06:22:00 DEBUG : sub dir/hello world: md5 = e6b972ec464424fc30b2f879f3010cfb OK 2025/05/01 06:22:00 INFO : sub dir/hello world: Copied (new) 2025/05/01 06:22:00 INFO : sub dir/hello world: Deleted 2025/05/01 06:22:00 INFO : sub dir: Set directory modification time (using DirSetModTime) 2025/05/01 06:22:02 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestMoveNoEmptyDirectories (5.27s) === RUN TestSyncEmptyDirectories run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zedurer9kufu'", Local "Local file system at /tmp/rclone1815725417", Modify Window "1ms" 2025/05/01 06:22:03 DEBUG : sub dir2: Making directory with metadata 2025/05/01 06:22:03 INFO : sub dir2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2025/05/01 06:22:03 INFO : sub dir: Set directory modification time (using DirSetModTime) 2025/05/01 06:22:03 DEBUG : sub dir: Making directory with metadata 2025/05/01 06:22:04 INFO : sub dir: Made directory with metadata (mtime=2001-02-03T04:05:06.499999999Z) 2025/05/01 06:22:04 DEBUG : sub dir2: Making directory with metadata 2025/05/01 06:22:04 INFO : sub dir2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2025/05/01 06:22:04 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2025/05/01 06:22:04 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zedurer9kufu': Waiting for checks to finish 2025/05/01 06:22:04 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zedurer9kufu': Waiting for transfers to finish 2025/05/01 06:22:06 DEBUG : sub dir/hello world: md5 = 9351cc9792bc473dc2cbe479599cec24 OK 2025/05/01 06:22:06 INFO : sub dir/hello world: Copied (new) 2025/05/01 06:22:06 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zedurer9kufu'", Local "Local file system at /tmp/rclone1815725417", Modify Window "1ms" 2025/05/01 06:23:10 DEBUG : Config file has changed externally - reloading 2025/05/01 06:23:10 DEBUG : TestDrive: Loaded fresh token from config file 2025/05/01 06:23:12 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestSyncEmptyDirectories (70.13s) === RUN TestSyncSetDelayedModTimes run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zedurer9kufu'", Local "Local file system at /tmp/rclone1815725417", Modify Window "1ms" sync_test.go:507: Backend doesn't have DirModTimeUpdatesOnWrite set --- SKIP: TestSyncSetDelayedModTimes (0.44s) === RUN TestSyncNoEmptyDirectories run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zedurer9kufu'", Local "Local file system at /tmp/rclone1815725417", Modify Window "1ms" 2025/05/01 06:23:13 INFO : sub dir2: Making directory 2025/05/01 06:23:13 DEBUG : Added delayed dir = "sub dir", newDst= 2025/05/01 06:23:13 DEBUG : Added delayed dir = "sub dir2", newDst= 2025/05/01 06:23:13 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2025/05/01 06:23:13 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zedurer9kufu': Waiting for checks to finish 2025/05/01 06:23:13 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zedurer9kufu': Waiting for transfers to finish 2025/05/01 06:23:15 DEBUG : sub dir/hello world: md5 = 692a280ea12906c0807d90c787a22985 OK 2025/05/01 06:23:15 INFO : sub dir/hello world: Copied (new) 2025/05/01 06:23:15 DEBUG : Waiting for deletions to finish 2025/05/01 06:23:16 INFO : sub dir: Set directory modification time (using DirSetModTime) 2025/05/01 06:23:18 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestSyncNoEmptyDirectories (5.09s) === RUN TestServerSideCopy run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zedurer9kufu'", Local "Local file system at /tmp/rclone1815725417", Modify Window "1ms" 2025/05/01 06:23:20 DEBUG : sub dir/hello world: md5 = c4f08c8471d50d3c6aef07d2adafc69f OK 2025/05/01 06:23:21 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-recanuz8siza" 2025/05/01 06:23:21 DEBUG : Creating backend with remote "TestDrive:crypt/f60u7h1t8f2te92nb7bo4lv3aa8082qh866jbecm09ohdmdu9410" sync_test.go:590: Server side copy (if possible) Encrypted drive 'TestCryptDrive:rclone-test-zedurer9kufu' -> Encrypted drive 'TestCryptDrive:rclone-test-recanuz8siza' 2025/05/01 06:23:22 DEBUG : Added delayed dir = "sub dir", newDst= 2025/05/01 06:23:22 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2025/05/01 06:23:22 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-recanuz8siza': Waiting for checks to finish 2025/05/01 06:23:22 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-recanuz8siza': Waiting for transfers to finish 2025/05/01 06:23:25 INFO : sub dir/hello world: Copied (server-side copy) 2025/05/01 06:23:26 INFO : sub dir: Set directory modification time (using DirSetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zedurer9kufu'", Local "Local file system at /tmp/rclone1815725417", Modify Window "1ms" 2025/05/01 06:23:26 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-recanuz8siza': Purge remote 2025/05/01 06:23:28 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestServerSideCopy (10.88s) === RUN TestCopyOverSelf run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zedurer9kufu'", Local "Local file system at /tmp/rclone1815725417", Modify Window "1ms" 2025/05/01 06:23:31 DEBUG : sub dir/hello world: md5 = e17c76e61b88bad74f0bf30df2a81a85 OK 2025/05/01 06:23:32 INFO : sub dir: Set directory modification time (using SetModTime) 2025/05/01 06:23:32 DEBUG : Added delayed dir = "sub dir", newDst=sub dir 2025/05/01 06:23:33 DEBUG : sub dir/hello world: Sizes differ (src 17 vs dst 11) 2025/05/01 06:23:33 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zedurer9kufu': Waiting for checks to finish 2025/05/01 06:23:33 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zedurer9kufu': Waiting for transfers to finish 2025/05/01 06:23:34 DEBUG : sub dir/hello world: md5 = 18feb2099844675db117a072dd7cc5f5 OK 2025/05/01 06:23:34 INFO : sub dir/hello world: Copied (replaced existing) 2025/05/01 06:23:34 INFO : sub dir: Set directory modification time (using SetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zedurer9kufu'", Local "Local file system at /tmp/rclone1815725417", Modify Window "1ms" 2025/05/01 06:23:36 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestCopyOverSelf (8.57s) === RUN TestServerSideCopyOverSelf run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zedurer9kufu'", Local "Local file system at /tmp/rclone1815725417", Modify Window "1ms" 2025/05/01 06:23:40 DEBUG : sub dir/hello world: md5 = 5e5fbabd0876e6f76bff541adb65657a OK 2025/05/01 06:23:40 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-luvafab9xeke" 2025/05/01 06:23:40 DEBUG : Creating backend with remote "TestDrive:crypt/5cci2eapvi53732a1vjc3udms4ucmlvko0th9n62c6oo19h6odag" sync_test.go:626: Server side copy (if possible) Encrypted drive 'TestCryptDrive:rclone-test-zedurer9kufu' -> Encrypted drive 'TestCryptDrive:rclone-test-luvafab9xeke' 2025/05/01 06:23:41 DEBUG : Added delayed dir = "sub dir", newDst= 2025/05/01 06:23:42 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2025/05/01 06:23:42 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-luvafab9xeke': Waiting for checks to finish 2025/05/01 06:23:42 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-luvafab9xeke': Waiting for transfers to finish 2025/05/01 06:23:44 INFO : sub dir/hello world: Copied (server-side copy) 2025/05/01 06:23:45 INFO : sub dir: Set directory modification time (using DirSetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zedurer9kufu'", Local "Local file system at /tmp/rclone1815725417", Modify Window "1ms" 2025/05/01 06:23:47 DEBUG : sub dir/hello world: md5 = ba67b6a46d7f67d08e46efb371fdfbef OK 2025/05/01 06:23:47 DEBUG : sub dir: Directory modification time the same (differ by 0s, within tolerance 1ms) 2025/05/01 06:23:47 DEBUG : Added delayed dir = "sub dir", newDst=sub dir 2025/05/01 06:23:48 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-luvafab9xeke': Waiting for checks to finish 2025/05/01 06:23:48 DEBUG : sub dir/hello world: Sizes differ (src 17 vs dst 11) 2025/05/01 06:23:48 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-luvafab9xeke': Waiting for transfers to finish 2025/05/01 06:23:49 INFO : sub dir/hello world: Copied (server-side copy) 2025/05/01 06:23:50 INFO : sub dir: Set directory modification time (using SetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zedurer9kufu'", Local "Local file system at /tmp/rclone1815725417", Modify Window "1ms" 2025/05/01 06:23:50 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-luvafab9xeke': Purge remote 2025/05/01 06:23:52 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestServerSideCopyOverSelf (15.91s) === RUN TestMoveOverSelf run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zedurer9kufu'", Local "Local file system at /tmp/rclone1815725417", Modify Window "1ms" 2025/05/01 06:23:56 DEBUG : sub dir/hello world: md5 = 0e2f21cd2d8921125782d4f4be7c33af OK 2025/05/01 06:23:57 INFO : sub dir: Set directory modification time (using SetModTime) 2025/05/01 06:23:57 DEBUG : Added delayed dir = "sub dir", newDst=sub dir 2025/05/01 06:23:57 DEBUG : sub dir/hello world: Sizes differ (src 17 vs dst 11) 2025/05/01 06:23:57 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zedurer9kufu': Waiting for checks to finish 2025/05/01 06:23:57 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zedurer9kufu': Waiting for transfers to finish 2025/05/01 06:23:58 DEBUG : sub dir/hello world: md5 = 6568589575a1ae7b3f3df9197fb82f22 OK 2025/05/01 06:23:58 INFO : sub dir/hello world: Copied (replaced existing) 2025/05/01 06:23:58 INFO : sub dir/hello world: Deleted 2025/05/01 06:23:59 INFO : sub dir: Set directory modification time (using SetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zedurer9kufu'", Local "Local file system at /tmp/rclone1815725417", Modify Window "1ms" 2025/05/01 06:24:00 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestMoveOverSelf (7.75s) === RUN TestServerSideMoveOverSelf run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zedurer9kufu'", Local "Local file system at /tmp/rclone1815725417", Modify Window "1ms" 2025/05/01 06:24:04 DEBUG : sub dir/hello world: md5 = 009080f3e884daf62eadef45690a3c42 OK 2025/05/01 06:24:04 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-rewutaw6qoda" 2025/05/01 06:24:04 DEBUG : Creating backend with remote "TestDrive:crypt/sso9qh9saanmi98ibi4sm92laovascvdaosl8c74ioppae5qup70" 2025/05/01 06:24:04 DEBUG : Config file has changed externally - reloading sync_test.go:671: Server side copy (if possible) Encrypted drive 'TestCryptDrive:rclone-test-zedurer9kufu' -> Encrypted drive 'TestCryptDrive:rclone-test-rewutaw6qoda' 2025/05/01 06:24:05 DEBUG : Added delayed dir = "sub dir", newDst= 2025/05/01 06:24:05 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2025/05/01 06:24:05 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-rewutaw6qoda': Waiting for checks to finish 2025/05/01 06:24:05 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-rewutaw6qoda': Waiting for transfers to finish 2025/05/01 06:24:08 INFO : sub dir/hello world: Copied (server-side copy) 2025/05/01 06:24:09 INFO : sub dir: Set directory modification time (using DirSetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zedurer9kufu'", Local "Local file system at /tmp/rclone1815725417", Modify Window "1ms" 2025/05/01 06:24:11 DEBUG : sub dir/hello world: md5 = a0b1257fc52fbc9189843459f4f313de OK 2025/05/01 06:24:11 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-rewutaw6qoda': Using server-side directory move 2025/05/01 06:24:11 INFO : Encrypted drive 'TestCryptDrive:rclone-test-rewutaw6qoda': Server side directory move failed - fallback to file moves: can't copy directory - destination already exists 2025/05/01 06:24:11 DEBUG : sub dir: Directory modification time the same (differ by 0s, within tolerance 1ms) 2025/05/01 06:24:11 DEBUG : Added delayed dir = "sub dir", newDst=sub dir 2025/05/01 06:24:12 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-rewutaw6qoda': Waiting for checks to finish 2025/05/01 06:24:12 DEBUG : sub dir/hello world: Sizes differ (src 17 vs dst 11) 2025/05/01 06:24:12 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-rewutaw6qoda': Waiting for transfers to finish 2025/05/01 06:24:12 INFO : sub dir/hello world: Deleted 2025/05/01 06:24:13 INFO : sub dir/hello world: Moved (server-side) 2025/05/01 06:24:13 INFO : sub dir: Set directory modification time (using SetModTime) 2025/05/01 06:24:15 DEBUG : sub dir/hello world: md5 = 3b71c865941d56adbe4ea83e23cf1bb8 OK 2025/05/01 06:24:16 DEBUG : testing file moves 2025/05/01 06:24:16 DEBUG : sub dir: Directory modification time the same (differ by 0s, within tolerance 1ms) 2025/05/01 06:24:16 DEBUG : Added delayed dir = "sub dir", newDst=sub dir 2025/05/01 06:24:16 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-rewutaw6qoda': Waiting for checks to finish 2025/05/01 06:24:16 DEBUG : sub dir/hello world: Sizes differ (src 24 vs dst 17) 2025/05/01 06:24:16 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-rewutaw6qoda': Waiting for transfers to finish 2025/05/01 06:24:17 INFO : sub dir/hello world: Deleted 2025/05/01 06:24:17 INFO : sub dir/hello world: Moved (server-side) 2025/05/01 06:24:18 INFO : sub dir: Set directory modification time (using SetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zedurer9kufu'", Local "Local file system at /tmp/rclone1815725417", Modify Window "1ms" 2025/05/01 06:24:19 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-rewutaw6qoda': Purge remote --- PASS: TestServerSideMoveOverSelf (19.98s) === RUN TestCopyAfterDelete run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zedurer9kufu'", Local "Local file system at /tmp/rclone1815725417", Modify Window "1ms" 2025/05/01 06:24:23 DEBUG : sub dir/hello world: md5 = 83ce9e3a7543495296cd2468b0c18b81 OK 2025/05/01 06:24:23 ERROR : : error listing: directory not found 2025/05/01 06:24:24 INFO : Local file system at /tmp/rclone1815725417: Making directory 2025/05/01 06:24:24 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zedurer9kufu': Waiting for checks to finish 2025/05/01 06:24:24 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zedurer9kufu': Waiting for transfers to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zedurer9kufu'", Local "Local file system at /tmp/rclone1815725417", Modify Window "1ms" 2025/05/01 06:24:26 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestCopyAfterDelete (5.84s) === RUN TestCopyRedownload run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zedurer9kufu'", Local "Local file system at /tmp/rclone1815725417", Modify Window "1ms" 2025/05/01 06:24:29 DEBUG : sub dir/hello world: md5 = 34abc47922fd4aafa4b2a928382172d9 OK 2025/05/01 06:24:30 DEBUG : Added delayed dir = "sub dir", newDst= 2025/05/01 06:24:30 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2025/05/01 06:24:30 DEBUG : Local file system at /tmp/rclone1815725417: Waiting for checks to finish 2025/05/01 06:24:30 DEBUG : Local file system at /tmp/rclone1815725417: Waiting for transfers to finish 2025/05/01 06:24:31 DEBUG : sub dir/hello world.285f0a30.partial: renamed to: sub dir/hello world 2025/05/01 06:24:31 INFO : sub dir/hello world: Copied (new) 2025/05/01 06:24:31 INFO : sub dir: Set directory modification time (using DirSetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zedurer9kufu'", Local "Local file system at /tmp/rclone1815725417", Modify Window "1ms" 2025/05/01 06:24:32 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestCopyRedownload (6.83s) === RUN TestSyncBasedOnCheckSum run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zedurer9kufu'", Local "Local file system at /tmp/rclone1815725417", Modify Window "1ms" 2025/05/01 06:24:34 DEBUG : check sum: Need to transfer - File not found at Destination 2025/05/01 06:24:34 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zedurer9kufu': Waiting for checks to finish 2025/05/01 06:24:34 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zedurer9kufu': Waiting for transfers to finish 2025/05/01 06:24:35 DEBUG : check sum: md5 = dcf6f998b8c432ac11e656878d21761e OK 2025/05/01 06:24:35 INFO : check sum: Copied (new) 2025/05/01 06:24:35 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zedurer9kufu'", Local "Local file system at /tmp/rclone1815725417", Modify Window "1ms" 2025/05/01 06:24:36 NOTICE: Encrypted drive 'TestCryptDrive:rclone-test-zedurer9kufu': --checksum is in use but the source and destination have no hashes in common; falling back to --size-only 2025/05/01 06:24:36 DEBUG : check sum: Size of src and dst objects identical 2025/05/01 06:24:36 DEBUG : check sum: Unchanged skipping 2025/05/01 06:24:36 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zedurer9kufu': Waiting for checks to finish 2025/05/01 06:24:36 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zedurer9kufu': Waiting for transfers to finish 2025/05/01 06:24:36 DEBUG : Waiting for deletions to finish 2025/05/01 06:24:36 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zedurer9kufu'", Local "Local file system at /tmp/rclone1815725417", Modify Window "1ms" --- PASS: TestSyncBasedOnCheckSum (8.55s) === RUN TestSyncSizeOnly run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zedurer9kufu'", Local "Local file system at /tmp/rclone1815725417", Modify Window "1ms" 2025/05/01 06:24:43 DEBUG : sizeonly: Need to transfer - File not found at Destination 2025/05/01 06:24:43 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zedurer9kufu': Waiting for checks to finish 2025/05/01 06:24:43 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zedurer9kufu': Waiting for transfers to finish 2025/05/01 06:24:45 DEBUG : sizeonly: md5 = 8c27e2f1dba85ab5ac48caa7c9c5e438 OK 2025/05/01 06:24:45 INFO : sizeonly: Copied (new) 2025/05/01 06:24:45 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zedurer9kufu'", Local "Local file system at /tmp/rclone1815725417", Modify Window "1ms" 2025/05/01 06:24:46 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zedurer9kufu': Waiting for checks to finish 2025/05/01 06:24:46 DEBUG : sizeonly: Sizes identical 2025/05/01 06:24:46 DEBUG : sizeonly: Unchanged skipping 2025/05/01 06:24:46 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zedurer9kufu': Waiting for transfers to finish 2025/05/01 06:24:46 DEBUG : Waiting for deletions to finish 2025/05/01 06:24:46 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zedurer9kufu'", Local "Local file system at /tmp/rclone1815725417", Modify Window "1ms" --- PASS: TestSyncSizeOnly (5.30s) === RUN TestSyncIgnoreSize run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zedurer9kufu'", Local "Local file system at /tmp/rclone1815725417", Modify Window "1ms" 2025/05/01 06:24:48 DEBUG : ignore-size: Need to transfer - File not found at Destination 2025/05/01 06:24:48 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zedurer9kufu': Waiting for checks to finish 2025/05/01 06:24:48 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zedurer9kufu': Waiting for transfers to finish 2025/05/01 06:24:50 DEBUG : ignore-size: md5 = fd2686376b36fbb9963746967ad76d60 OK 2025/05/01 06:24:50 INFO : ignore-size: Copied (new) 2025/05/01 06:24:50 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zedurer9kufu'", Local "Local file system at /tmp/rclone1815725417", Modify Window "1ms" 2025/05/01 06:24:50 DEBUG : ignore-size: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/05/01 06:24:50 DEBUG : ignore-size: Unchanged skipping 2025/05/01 06:24:50 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zedurer9kufu': Waiting for checks to finish 2025/05/01 06:24:50 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zedurer9kufu': Waiting for transfers to finish 2025/05/01 06:24:50 DEBUG : Waiting for deletions to finish 2025/05/01 06:24:50 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zedurer9kufu'", Local "Local file system at /tmp/rclone1815725417", Modify Window "1ms" --- PASS: TestSyncIgnoreSize (4.33s) === RUN TestSyncIgnoreTimes run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zedurer9kufu'", Local "Local file system at /tmp/rclone1815725417", Modify Window "1ms" 2025/05/01 06:24:54 DEBUG : existing: md5 = 170262e83a39a2c1c02666d3f5c0b1b3 OK 2025/05/01 06:24:54 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zedurer9kufu': Waiting for checks to finish 2025/05/01 06:24:54 DEBUG : existing: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/05/01 06:24:54 DEBUG : existing: Unchanged skipping 2025/05/01 06:24:54 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zedurer9kufu': Waiting for transfers to finish 2025/05/01 06:24:54 DEBUG : Waiting for deletions to finish 2025/05/01 06:24:54 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zedurer9kufu'", Local "Local file system at /tmp/rclone1815725417", Modify Window "1ms" 2025/05/01 06:24:54 DEBUG : existing: Transferring unconditionally as --ignore-times is in use 2025/05/01 06:24:54 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zedurer9kufu': Waiting for checks to finish 2025/05/01 06:24:54 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zedurer9kufu': Waiting for transfers to finish 2025/05/01 06:24:56 DEBUG : existing: md5 = b02ec8a4bbdac970fb8436e1f6d31251 OK 2025/05/01 06:24:56 INFO : existing: Copied (replaced existing) 2025/05/01 06:24:56 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zedurer9kufu'", Local "Local file system at /tmp/rclone1815725417", Modify Window "1ms" --- PASS: TestSyncIgnoreTimes (5.43s) === RUN TestSyncIgnoreExisting run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zedurer9kufu'", Local "Local file system at /tmp/rclone1815725417", Modify Window "1ms" 2025/05/01 06:24:58 DEBUG : existing: Need to transfer - File not found at Destination 2025/05/01 06:24:58 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zedurer9kufu': Waiting for checks to finish 2025/05/01 06:24:58 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zedurer9kufu': Waiting for transfers to finish 2025/05/01 06:24:59 DEBUG : existing: md5 = f08595b1cc59db0505defbd0486fe8ef OK 2025/05/01 06:24:59 INFO : existing: Copied (new) 2025/05/01 06:24:59 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zedurer9kufu'", Local "Local file system at /tmp/rclone1815725417", Modify Window "1ms" 2025/05/01 06:25:00 DEBUG : existing: Destination exists, skipping 2025/05/01 06:25:00 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zedurer9kufu': Waiting for checks to finish 2025/05/01 06:25:00 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zedurer9kufu': Waiting for transfers to finish 2025/05/01 06:25:00 DEBUG : Waiting for deletions to finish 2025/05/01 06:25:00 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zedurer9kufu'", Local "Local file system at /tmp/rclone1815725417", Modify Window "1ms" --- PASS: TestSyncIgnoreExisting (4.21s) === RUN TestSyncIgnoreErrors run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zedurer9kufu'", Local "Local file system at /tmp/rclone1815725417", Modify Window "1ms" 2025/05/01 06:25:04 DEBUG : b/potato: md5 = c4e765df2ffffabe4ac074750375fafb OK 2025/05/01 06:25:07 DEBUG : c/non empty space: md5 = bdadd8e16812fc4038456f67a5d6fdd8 OK 2025/05/01 06:25:07 INFO : d: Making directory 2025/05/01 06:25:08 DEBUG : Added delayed dir = "a", newDst= 2025/05/01 06:25:09 INFO : c: Set directory modification time (using SetModTime) 2025/05/01 06:25:09 DEBUG : Added delayed dir = "c", newDst=c 2025/05/01 06:25:09 DEBUG : a/potato2: Need to transfer - File not found at Destination 2025/05/01 06:25:09 DEBUG : c/non empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/05/01 06:25:09 DEBUG : c/non empty space: Unchanged skipping 2025/05/01 06:25:09 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zedurer9kufu': Waiting for checks to finish 2025/05/01 06:25:09 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zedurer9kufu': Waiting for transfers to finish 2025/05/01 06:25:11 DEBUG : a/potato2: md5 = 7c0bb67493c8845a1713dfa07b1d79ec OK 2025/05/01 06:25:11 INFO : a/potato2: Copied (new) 2025/05/01 06:25:11 DEBUG : Waiting for deletions to finish 2025/05/01 06:25:11 INFO : b/potato: Deleted 2025/05/01 06:25:12 INFO : a: Set directory modification time (using DirSetModTime) 2025/05/01 06:25:12 INFO : d: Removing directory 2025/05/01 06:25:12 INFO : b: Removing directory 2025/05/01 06:25:12 DEBUG : 32d8ua6196mc1r7qkfog53rkg0: Rmdir: contains trashed file: "2m507n64kafsi59v9q71r281a4" 2025/05/01 06:25:13 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zedurer9kufu': deleted 2 directories run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zedurer9kufu'", Local "Local file system at /tmp/rclone1815725417", Modify Window "1ms" 2025/05/01 06:25:15 DEBUG : 3i9du405pfogq3ncai6pg7ouio: Rmdir: contains trashed file: "982d3pss7t5pn0il16r2foj31s" 2025/05/01 06:25:16 DEBUG : 2bsvlrk2ne1lfitm6tttcu0qt8: Rmdir: contains trashed file: "89l8renevh3mji1c8r1p7qn6tg" --- PASS: TestSyncIgnoreErrors (15.31s) === RUN TestSyncAfterChangingModtimeOnly run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zedurer9kufu'", Local "Local file system at /tmp/rclone1815725417", Modify Window "1ms" 2025/05/01 06:25:19 DEBUG : empty space: md5 = c6c4c529207473a5222afa1c3941420e OK 2025/05/01 06:25:19 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/05/01 06:25:19 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zedurer9kufu': Waiting for checks to finish 2025/05/01 06:25:19 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zedurer9kufu': Waiting for transfers to finish 2025/05/01 06:25:19 NOTICE: empty space: Skipped copy as --dry-run is set (size 1) 2025/05/01 06:25:19 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zedurer9kufu'", Local "Local file system at /tmp/rclone1815725417", Modify Window "1ms" 2025/05/01 06:25:19 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/05/01 06:25:19 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zedurer9kufu': Waiting for checks to finish 2025/05/01 06:25:19 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zedurer9kufu': Waiting for transfers to finish 2025/05/01 06:25:21 DEBUG : empty space: md5 = bb90d4a4a18b7b83bfed8f990ea48b90 OK 2025/05/01 06:25:21 INFO : empty space: Copied (replaced existing) 2025/05/01 06:25:21 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zedurer9kufu'", Local "Local file system at /tmp/rclone1815725417", Modify Window "1ms" --- PASS: TestSyncAfterChangingModtimeOnly (5.56s) === RUN TestSyncAfterChangingModtimeOnlyWithNoUpdateModTime run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zedurer9kufu'", Local "Local file system at /tmp/rclone1815725417", Modify Window "1ms" sync_test.go:1016: Can't check this if no hashes supported --- PASS: TestSyncAfterChangingModtimeOnlyWithNoUpdateModTime (0.45s) === RUN TestSyncDoesntUpdateModtime run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zedurer9kufu'", Local "Local file system at /tmp/rclone1815725417", Modify Window "1ms" 2025/05/01 06:25:24 DEBUG : foo: md5 = 441dae9684d71fc4c93306e679bfbbc8 OK 2025/05/01 06:25:25 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/05/01 06:25:25 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zedurer9kufu': Waiting for checks to finish 2025/05/01 06:25:25 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zedurer9kufu': Waiting for transfers to finish 2025/05/01 06:25:26 DEBUG : foo: md5 = 15f17486018ebadc5e4ee261e1d49df7 OK 2025/05/01 06:25:26 INFO : foo: Copied (replaced existing) 2025/05/01 06:25:26 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zedurer9kufu'", Local "Local file system at /tmp/rclone1815725417", Modify Window "1ms" --- PASS: TestSyncDoesntUpdateModtime (4.54s) === RUN TestSyncAfterAddingAFile run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zedurer9kufu'", Local "Local file system at /tmp/rclone1815725417", Modify Window "1ms" 2025/05/01 06:25:29 DEBUG : empty space: md5 = 78d5638ec3c08c73b837087b433e2d8c OK 2025/05/01 06:25:29 DEBUG : empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/05/01 06:25:29 DEBUG : potato: Need to transfer - File not found at Destination 2025/05/01 06:25:29 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zedurer9kufu': Waiting for checks to finish 2025/05/01 06:25:29 DEBUG : empty space: Unchanged skipping 2025/05/01 06:25:29 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zedurer9kufu': Waiting for transfers to finish 2025/05/01 06:25:31 DEBUG : potato: md5 = ef8d5aba5f8bf76aa6ad652acd963af3 OK 2025/05/01 06:25:31 INFO : potato: Copied (new) 2025/05/01 06:25:31 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zedurer9kufu'", Local "Local file system at /tmp/rclone1815725417", Modify Window "1ms" --- PASS: TestSyncAfterAddingAFile (5.33s) === RUN TestSyncAfterChangingFilesSizeOnly run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zedurer9kufu'", Local "Local file system at /tmp/rclone1815725417", Modify Window "1ms" 2025/05/01 06:25:34 DEBUG : potato: md5 = c79a4327990d8861ecbbd34219c606b0 OK 2025/05/01 06:25:35 DEBUG : potato: Sizes differ (src 21 vs dst 60) 2025/05/01 06:25:35 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zedurer9kufu': Waiting for checks to finish 2025/05/01 06:25:35 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zedurer9kufu': Waiting for transfers to finish 2025/05/01 06:25:36 DEBUG : potato: md5 = 08d1f92f579ea939166564df51c27597 OK 2025/05/01 06:25:36 INFO : potato: Copied (replaced existing) 2025/05/01 06:25:36 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zedurer9kufu'", Local "Local file system at /tmp/rclone1815725417", Modify Window "1ms" --- PASS: TestSyncAfterChangingFilesSizeOnly (4.35s) === RUN TestSyncAfterChangingContentsOnly run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zedurer9kufu'", Local "Local file system at /tmp/rclone1815725417", Modify Window "1ms" 2025/05/01 06:25:39 DEBUG : potato: md5 = 099afb93d051333e85ebfbcad264cb9e OK 2025/05/01 06:25:39 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/05/01 06:25:39 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zedurer9kufu': Waiting for checks to finish 2025/05/01 06:25:39 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zedurer9kufu': Waiting for transfers to finish 2025/05/01 06:25:41 DEBUG : potato: md5 = 9692f342971858f9a56b75f80d4b04b4 OK 2025/05/01 06:25:41 INFO : potato: Copied (replaced existing) 2025/05/01 06:25:41 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zedurer9kufu'", Local "Local file system at /tmp/rclone1815725417", Modify Window "1ms" --- PASS: TestSyncAfterChangingContentsOnly (4.91s) === RUN TestSyncAfterRemovingAFileAndAddingAFileDryRun run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zedurer9kufu'", Local "Local file system at /tmp/rclone1815725417", Modify Window "1ms" 2025/05/01 06:25:44 DEBUG : potato: md5 = e926b985f7ddfe5421965ecee18ecc2c OK 2025/05/01 06:25:45 DEBUG : empty space: md5 = 575c22f566796f6d20abce3721964cf0 OK 2025/05/01 06:25:46 DEBUG : potato2: Need to transfer - File not found at Destination 2025/05/01 06:25:46 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zedurer9kufu': Waiting for checks to finish 2025/05/01 06:25:46 NOTICE: potato2: Skipped copy as --dry-run is set (size 60) 2025/05/01 06:25:46 DEBUG : empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/05/01 06:25:46 DEBUG : empty space: Unchanged skipping 2025/05/01 06:25:46 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zedurer9kufu': Waiting for transfers to finish 2025/05/01 06:25:46 DEBUG : Waiting for deletions to finish 2025/05/01 06:25:46 NOTICE: potato: Skipped delete as --dry-run is set (size 21) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zedurer9kufu'", Local "Local file system at /tmp/rclone1815725417", Modify Window "1ms" --- PASS: TestSyncAfterRemovingAFileAndAddingAFileDryRun (5.51s) === RUN TestSyncAfterRemovingAFileAndAddingAFile run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zedurer9kufu'", Local "Local file system at /tmp/rclone1815725417", Modify Window "1ms" 2025/05/01 06:25:49 DEBUG : potato: md5 = 75e49aebfeb0022cabdf8f8a6f017870 OK 2025/05/01 06:25:51 DEBUG : empty space: md5 = 704291d44d828ca82057161afdf5c19b OK 2025/05/01 06:25:51 DEBUG : empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/05/01 06:25:51 DEBUG : potato2: Need to transfer - File not found at Destination 2025/05/01 06:25:51 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zedurer9kufu': Waiting for checks to finish 2025/05/01 06:25:51 DEBUG : empty space: Unchanged skipping 2025/05/01 06:25:51 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zedurer9kufu': Waiting for transfers to finish 2025/05/01 06:25:52 DEBUG : potato2: md5 = fcb2a041e5027b0f1ef3b9dc86d0f7cb OK 2025/05/01 06:25:52 INFO : potato2: Copied (new) 2025/05/01 06:25:52 DEBUG : Waiting for deletions to finish 2025/05/01 06:25:53 INFO : potato: Deleted run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zedurer9kufu'", Local "Local file system at /tmp/rclone1815725417", Modify Window "1ms" --- PASS: TestSyncAfterRemovingAFileAndAddingAFile (7.16s) === RUN TestSyncAfterRemovingAFileAndAddingAFileSubDir run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zedurer9kufu'", Local "Local file system at /tmp/rclone1815725417", Modify Window "1ms" 2025/05/01 06:25:57 DEBUG : b/potato: md5 = 6dbe9e1381090ef9457e511fcaa5c251 OK 2025/05/01 06:26:00 DEBUG : c/non empty space: md5 = 116881af890a0b522e7fa83a45d1c70e OK 2025/05/01 06:26:00 INFO : d: Making directory 2025/05/01 06:26:01 INFO : d/e: Making directory 2025/05/01 06:26:02 DEBUG : Added delayed dir = "a", newDst= 2025/05/01 06:26:03 INFO : c: Set directory modification time (using SetModTime) 2025/05/01 06:26:03 DEBUG : Added delayed dir = "c", newDst=c 2025/05/01 06:26:03 DEBUG : a/potato2: Need to transfer - File not found at Destination 2025/05/01 06:26:03 DEBUG : c/non empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/05/01 06:26:03 DEBUG : c/non empty space: Unchanged skipping 2025/05/01 06:26:04 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zedurer9kufu': Waiting for checks to finish 2025/05/01 06:26:04 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zedurer9kufu': Waiting for transfers to finish 2025/05/01 06:26:05 DEBUG : a/potato2: md5 = 3969b2f6b1f5c0afbe3a7f341f7bb2c8 OK 2025/05/01 06:26:05 INFO : a/potato2: Copied (new) 2025/05/01 06:26:05 DEBUG : Waiting for deletions to finish 2025/05/01 06:26:05 INFO : b/potato: Deleted 2025/05/01 06:26:06 INFO : a: Set directory modification time (using DirSetModTime) 2025/05/01 06:26:06 INFO : d/e: Removing directory 2025/05/01 06:26:07 INFO : d: Removing directory 2025/05/01 06:26:07 DEBUG : ka6id8d20d3s5ktapedlphgta8: Rmdir: contains trashed file: "r8sppajuabeak3sbgj2ak8vuf8" 2025/05/01 06:26:07 INFO : b: Removing directory 2025/05/01 06:26:08 DEBUG : 32d8ua6196mc1r7qkfog53rkg0: Rmdir: contains trashed file: "2m507n64kafsi59v9q71r281a4" 2025/05/01 06:26:08 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zedurer9kufu': deleted 3 directories run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zedurer9kufu'", Local "Local file system at /tmp/rclone1815725417", Modify Window "1ms" 2025/05/01 06:26:10 DEBUG : 3i9du405pfogq3ncai6pg7ouio: Rmdir: contains trashed file: "982d3pss7t5pn0il16r2foj31s" 2025/05/01 06:26:11 DEBUG : 2bsvlrk2ne1lfitm6tttcu0qt8: Rmdir: contains trashed file: "89l8renevh3mji1c8r1p7qn6tg" --- PASS: TestSyncAfterRemovingAFileAndAddingAFileSubDir (17.28s) === RUN TestSyncAfterRemovingAFileAndAddingAFileSubDirWithErrors run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zedurer9kufu'", Local "Local file system at /tmp/rclone1815725417", Modify Window "1ms" 2025/05/01 06:26:14 DEBUG : b/potato: md5 = eaa436649373bc57dece37cf56d238aa OK 2025/05/01 06:26:16 DEBUG : c/non empty space: md5 = 088b44e499f35b08625fa951e3770ec8 OK 2025/05/01 06:26:16 INFO : d: Making directory 2025/05/01 06:26:18 DEBUG : Added delayed dir = "a", newDst= 2025/05/01 06:26:18 INFO : c: Set directory modification time (using SetModTime) 2025/05/01 06:26:18 DEBUG : Added delayed dir = "c", newDst=c 2025/05/01 06:26:18 DEBUG : a/potato2: Need to transfer - File not found at Destination 2025/05/01 06:26:19 DEBUG : c/non empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/05/01 06:26:19 DEBUG : c/non empty space: Unchanged skipping 2025/05/01 06:26:19 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zedurer9kufu': Waiting for checks to finish 2025/05/01 06:26:19 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zedurer9kufu': Waiting for transfers to finish 2025/05/01 06:26:21 DEBUG : a/potato2: md5 = 0bbc0a99ed0deffcb9337cf4ce6a726d OK 2025/05/01 06:26:21 INFO : a/potato2: Copied (new) 2025/05/01 06:26:21 ERROR : Encrypted drive 'TestCryptDrive:rclone-test-zedurer9kufu': not deleting files as there were IO errors 2025/05/01 06:26:21 INFO : a: Set directory modification time (using DirSetModTime) 2025/05/01 06:26:21 ERROR : Encrypted drive 'TestCryptDrive:rclone-test-zedurer9kufu': not deleting directories as there were IO errors run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zedurer9kufu'", Local "Local file system at /tmp/rclone1815725417", Modify Window "1ms" 2025/05/01 06:26:24 DEBUG : 3i9du405pfogq3ncai6pg7ouio: Rmdir: contains trashed file: "982d3pss7t5pn0il16r2foj31s" 2025/05/01 06:26:25 DEBUG : 32d8ua6196mc1r7qkfog53rkg0: Rmdir: contains trashed file: "2m507n64kafsi59v9q71r281a4" 2025/05/01 06:26:26 DEBUG : 2bsvlrk2ne1lfitm6tttcu0qt8: Rmdir: contains trashed file: "89l8renevh3mji1c8r1p7qn6tg" --- PASS: TestSyncAfterRemovingAFileAndAddingAFileSubDirWithErrors (14.82s) === RUN TestSyncDeleteAfter --- PASS: TestSyncDeleteAfter (0.00s) === RUN TestSyncDeleteDuring run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zedurer9kufu'", Local "Local file system at /tmp/rclone1815725417", Modify Window "1ms" 2025/05/01 06:26:29 DEBUG : potato: md5 = 635477942c8065adb9c8fcad6ae61d5a OK 2025/05/01 06:26:30 DEBUG : empty space: md5 = 9a7ac8c55b3bbdb2322de8099020d37e OK 2025/05/01 06:26:30 DEBUG : Waiting for deletions to finish 2025/05/01 06:26:30 DEBUG : empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/05/01 06:26:30 DEBUG : potato2: Need to transfer - File not found at Destination 2025/05/01 06:26:30 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zedurer9kufu': Waiting for checks to finish 2025/05/01 06:26:30 DEBUG : empty space: Unchanged skipping 2025/05/01 06:26:30 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zedurer9kufu': Waiting for transfers to finish 2025/05/01 06:26:31 INFO : potato: Deleted 2025/05/01 06:26:32 DEBUG : potato2: md5 = 237287bbe87fd00f3cecd30ecb0a321f OK 2025/05/01 06:26:32 INFO : potato2: Copied (new) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zedurer9kufu'", Local "Local file system at /tmp/rclone1815725417", Modify Window "1ms" --- PASS: TestSyncDeleteDuring (6.94s) === RUN TestSyncDeleteBefore run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zedurer9kufu'", Local "Local file system at /tmp/rclone1815725417", Modify Window "1ms" 2025/05/01 06:26:35 DEBUG : potato: md5 = ec597001ca3fe7314656363a9a213381 OK 2025/05/01 06:26:37 DEBUG : empty space: md5 = e94938b2bc1c0776d9f3074143f5cc9c OK 2025/05/01 06:26:37 DEBUG : Waiting for deletions to finish 2025/05/01 06:26:37 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zedurer9kufu': Waiting for checks to finish 2025/05/01 06:26:37 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zedurer9kufu': Waiting for transfers to finish 2025/05/01 06:26:38 INFO : potato: Deleted 2025/05/01 06:26:38 DEBUG : empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/05/01 06:26:38 DEBUG : potato2: Need to transfer - File not found at Destination 2025/05/01 06:26:38 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zedurer9kufu': Waiting for checks to finish 2025/05/01 06:26:38 DEBUG : empty space: Unchanged skipping 2025/05/01 06:26:38 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zedurer9kufu': Waiting for transfers to finish 2025/05/01 06:26:39 DEBUG : potato2: md5 = 649e130310ababc5eca5ca8f91c93385 OK 2025/05/01 06:26:39 INFO : potato2: Copied (new) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zedurer9kufu'", Local "Local file system at /tmp/rclone1815725417", Modify Window "1ms" --- PASS: TestSyncDeleteBefore (7.41s) === RUN TestCopyDeleteBefore run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zedurer9kufu'", Local "Local file system at /tmp/rclone1815725417", Modify Window "1ms" 2025/05/01 06:26:43 DEBUG : potato: md5 = 256644a3cca25fc803de0f7df81c2568 OK 2025/05/01 06:26:43 DEBUG : potato2: Need to transfer - File not found at Destination 2025/05/01 06:26:43 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zedurer9kufu': Waiting for checks to finish 2025/05/01 06:26:43 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zedurer9kufu': Waiting for transfers to finish 2025/05/01 06:26:44 DEBUG : potato2: md5 = d92110d63a91dd16e5e056d3ea8602ef OK 2025/05/01 06:26:44 INFO : potato2: Copied (new) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zedurer9kufu'", Local "Local file system at /tmp/rclone1815725417", Modify Window "1ms" --- PASS: TestCopyDeleteBefore (5.12s) === RUN TestSyncWithExclude run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zedurer9kufu'", Local "Local file system at /tmp/rclone1815725417", Modify Window "1ms" 2025/05/01 06:26:48 DEBUG : potato2: md5 = ac1adddb90f5487d774581393d108cfc OK 2025/05/01 06:26:49 DEBUG : empty space: md5 = 190b6d8df3f9f1a97db2333f5e49d920 OK 2025/05/01 06:26:49 DEBUG : enormous: Excluded (Size Filter) 2025/05/01 06:26:49 DEBUG : enormous: Excluded 2025/05/01 06:26:49 DEBUG : potato2: Excluded (Size Filter) 2025/05/01 06:26:49 DEBUG : potato2: Excluded 2025/05/01 06:26:50 DEBUG : potato2: Excluded (Size Filter) 2025/05/01 06:26:50 DEBUG : potato2: Excluded 2025/05/01 06:26:50 DEBUG : empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/05/01 06:26:50 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zedurer9kufu': Waiting for checks to finish 2025/05/01 06:26:50 DEBUG : empty space: Unchanged skipping 2025/05/01 06:26:50 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zedurer9kufu': Waiting for transfers to finish 2025/05/01 06:26:50 DEBUG : Waiting for deletions to finish 2025/05/01 06:26:50 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zedurer9kufu'", Local "Local file system at /tmp/rclone1815725417", Modify Window "1ms" 2025/05/01 06:26:50 DEBUG : enormous: Excluded (Size Filter) 2025/05/01 06:26:50 DEBUG : enormous: Excluded 2025/05/01 06:26:50 DEBUG : potato2: Excluded (Size Filter) 2025/05/01 06:26:50 DEBUG : potato2: Excluded 2025/05/01 06:26:50 DEBUG : potato2: Excluded (Size Filter) 2025/05/01 06:26:50 DEBUG : potato2: Excluded 2025/05/01 06:26:50 DEBUG : empty space: Size and modification time the same (differ by 456.789µs, within tolerance 1ms) 2025/05/01 06:26:50 DEBUG : empty space: Unchanged skipping 2025/05/01 06:26:50 DEBUG : Local file system at /tmp/rclone1815725417: Waiting for checks to finish 2025/05/01 06:26:50 DEBUG : Local file system at /tmp/rclone1815725417: Waiting for transfers to finish 2025/05/01 06:26:50 DEBUG : Waiting for deletions to finish 2025/05/01 06:26:50 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zedurer9kufu'", Local "Local file system at /tmp/rclone1815725417", Modify Window "1ms" --- PASS: TestSyncWithExclude (5.86s) === RUN TestSyncWithExcludeAndDeleteExcluded run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zedurer9kufu'", Local "Local file system at /tmp/rclone1815725417", Modify Window "1ms" 2025/05/01 06:26:54 DEBUG : potato2: md5 = 83392982c874b06a84b4edc23704a4b2 OK 2025/05/01 06:26:55 DEBUG : empty space: md5 = bca06410a30647dd022b4f9e20128445 OK 2025/05/01 06:26:56 DEBUG : enormous: md5 = bd8e6b5b52ab1003249d3425bb84ac66 OK 2025/05/01 06:26:57 DEBUG : enormous: Excluded (Size Filter) 2025/05/01 06:26:57 DEBUG : enormous: Excluded 2025/05/01 06:26:57 DEBUG : potato2: Excluded (Size Filter) 2025/05/01 06:26:57 DEBUG : potato2: Excluded 2025/05/01 06:26:57 DEBUG : empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/05/01 06:26:57 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zedurer9kufu': Waiting for checks to finish 2025/05/01 06:26:57 DEBUG : empty space: Unchanged skipping 2025/05/01 06:26:57 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zedurer9kufu': Waiting for transfers to finish 2025/05/01 06:26:57 DEBUG : Waiting for deletions to finish 2025/05/01 06:26:57 INFO : enormous: Deleted 2025/05/01 06:26:57 INFO : potato2: Deleted 2025/05/01 06:26:57 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zedurer9kufu'", Local "Local file system at /tmp/rclone1815725417", Modify Window "1ms" 2025/05/01 06:26:58 DEBUG : empty space: Size and modification time the same (differ by 456.789µs, within tolerance 1ms) 2025/05/01 06:26:58 DEBUG : Local file system at /tmp/rclone1815725417: Waiting for checks to finish 2025/05/01 06:26:58 DEBUG : empty space: Unchanged skipping 2025/05/01 06:26:58 DEBUG : Local file system at /tmp/rclone1815725417: Waiting for transfers to finish 2025/05/01 06:26:58 DEBUG : Waiting for deletions to finish 2025/05/01 06:26:58 INFO : enormous: Deleted 2025/05/01 06:26:58 INFO : potato2: Deleted 2025/05/01 06:26:58 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zedurer9kufu'", Local "Local file system at /tmp/rclone1815725417", Modify Window "1ms" --- PASS: TestSyncWithExcludeAndDeleteExcluded (7.21s) === RUN TestSyncWithUpdateOlder run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zedurer9kufu'", Local "Local file system at /tmp/rclone1815725417", Modify Window "1ms" 2025/05/01 06:27:01 DEBUG : one: md5 = 9343dbcffbdea46a9a004ee209d7935e OK 2025/05/01 06:27:02 DEBUG : two: md5 = a3050c2f4a7fd844a66c4cdac44befef OK 2025/05/01 06:27:04 DEBUG : three: md5 = 9ca6eebbe5d5f62c65696a9dec8974f9 OK 2025/05/01 06:27:05 DEBUG : four: md5 = 3fe71c2b272a827b9e154f5ab740f64d OK 2025/05/01 06:27:05 DEBUG : five: Need to transfer - File not found at Destination 2025/05/01 06:27:05 DEBUG : four: Sizes differ (src 4 vs dst 8) 2025/05/01 06:27:05 DEBUG : one: Destination is newer than source, skipping 2025/05/01 06:27:05 DEBUG : three: Sizes identical 2025/05/01 06:27:05 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zedurer9kufu': Waiting for checks to finish 2025/05/01 06:27:05 DEBUG : four: Destination mod time is within 1s of source but files differ, transferring 2025/05/01 06:27:05 DEBUG : three: Destination mod time is within 1s of source and files identical, skipping 2025/05/01 06:27:05 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zedurer9kufu': Waiting for transfers to finish 2025/05/01 06:27:06 DEBUG : two: md5 = d4e371d67308c8c6699a7c8d3825cbd4 OK 2025/05/01 06:27:06 INFO : two: Copied (replaced existing) 2025/05/01 06:27:07 DEBUG : four: md5 = fb5adae0a40181ce0033a4e58082e307 OK 2025/05/01 06:27:07 INFO : four: Copied (replaced existing) 2025/05/01 06:27:07 DEBUG : five: md5 = 6e6918b3376a94dbad2365ef77633b4b OK 2025/05/01 06:27:07 INFO : five: Copied (new) 2025/05/01 06:27:07 DEBUG : Waiting for deletions to finish sync_test.go:1449: Skip test with --checksum as no hashes supported --- PASS: TestSyncWithUpdateOlder (10.06s) === 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-zedurer9kufu'", Local "Local file system at /tmp/rclone1815725417", Modify Window "1ms" sync_test.go:1538: Can track renames: false 2025/05/01 06:27:10 ERROR : Encrypted drive 'TestCryptDrive:rclone-test-zedurer9kufu': Ignoring --track-renames as the source and destination do not have a common hash 2025/05/01 06:27:10 DEBUG : potato: Need to transfer - File not found at Destination 2025/05/01 06:27:10 DEBUG : yam: Need to transfer - File not found at Destination 2025/05/01 06:27:10 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zedurer9kufu': Waiting for checks to finish 2025/05/01 06:27:10 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zedurer9kufu': Waiting for transfers to finish 2025/05/01 06:27:11 DEBUG : potato: md5 = b6c9660e04a22eb226e33a66d6909dab OK 2025/05/01 06:27:11 INFO : potato: Copied (new) 2025/05/01 06:27:11 DEBUG : yam: md5 = 608d564557dd08c098e1407ca1145dde OK 2025/05/01 06:27:11 INFO : yam: Copied (new) 2025/05/01 06:27:11 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zedurer9kufu'", Local "Local file system at /tmp/rclone1815725417", Modify Window "1ms" 2025/05/01 06:27:12 ERROR : Encrypted drive 'TestCryptDrive:rclone-test-zedurer9kufu': Ignoring --track-renames as the source and destination do not have a common hash 2025/05/01 06:27:12 DEBUG : potato: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/05/01 06:27:12 DEBUG : yaml: Need to transfer - File not found at Destination 2025/05/01 06:27:12 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zedurer9kufu': Waiting for checks to finish 2025/05/01 06:27:12 DEBUG : potato: Unchanged skipping 2025/05/01 06:27:12 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zedurer9kufu': Waiting for transfers to finish 2025/05/01 06:27:13 DEBUG : yaml: md5 = 3b4aa5def2fea439358ed34546fc2277 OK 2025/05/01 06:27:13 INFO : yaml: Copied (new) 2025/05/01 06:27:13 DEBUG : Waiting for deletions to finish 2025/05/01 06:27:13 INFO : yam: Deleted run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zedurer9kufu'", Local "Local file system at /tmp/rclone1815725417", Modify Window "1ms" --- PASS: TestSyncWithTrackRenames (6.29s) === RUN TestParseRenamesStrategyModtime --- PASS: TestParseRenamesStrategyModtime (0.00s) === RUN TestRenamesStrategyModtime --- PASS: TestRenamesStrategyModtime (0.00s) === RUN TestSyncWithTrackRenamesStrategyModtime run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zedurer9kufu'", Local "Local file system at /tmp/rclone1815725417", Modify Window "1ms" sync_test.go:1610: Can track renames: true 2025/05/01 06:27:16 INFO : Encrypted drive 'TestCryptDrive:rclone-test-zedurer9kufu': Making map for --track-renames 2025/05/01 06:27:16 INFO : Encrypted drive 'TestCryptDrive:rclone-test-zedurer9kufu': Finished making map for --track-renames 2025/05/01 06:27:16 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zedurer9kufu': Waiting for checks to finish 2025/05/01 06:27:16 DEBUG : potato: Need to transfer - No matching file found at Destination 2025/05/01 06:27:16 DEBUG : yam: Need to transfer - No matching file found at Destination 2025/05/01 06:27:16 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zedurer9kufu': Waiting for renames to finish 2025/05/01 06:27:16 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zedurer9kufu': Waiting for transfers to finish 2025/05/01 06:27:17 DEBUG : yam: md5 = b31e969402c92d60e57b6f56c4d1fe62 OK 2025/05/01 06:27:17 INFO : yam: Copied (new) 2025/05/01 06:27:17 DEBUG : potato: md5 = 8f97444cc2cec28ee9081d87ad72bef2 OK 2025/05/01 06:27:17 INFO : potato: Copied (new) 2025/05/01 06:27:17 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zedurer9kufu'", Local "Local file system at /tmp/rclone1815725417", Modify Window "1ms" 2025/05/01 06:27:18 DEBUG : potato: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/05/01 06:27:18 INFO : Encrypted drive 'TestCryptDrive:rclone-test-zedurer9kufu': Making map for --track-renames 2025/05/01 06:27:18 INFO : Encrypted drive 'TestCryptDrive:rclone-test-zedurer9kufu': Finished making map for --track-renames 2025/05/01 06:27:18 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zedurer9kufu': Waiting for checks to finish 2025/05/01 06:27:18 DEBUG : potato: Unchanged skipping 2025/05/01 06:27:18 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zedurer9kufu': Waiting for renames to finish 2025/05/01 06:27:19 INFO : yam: Moved (server-side) to: yaml 2025/05/01 06:27:19 INFO : yaml: Renamed from "yam" 2025/05/01 06:27:19 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zedurer9kufu': Waiting for transfers to finish 2025/05/01 06:27:19 DEBUG : Waiting for deletions to finish 2025/05/01 06:27:19 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zedurer9kufu'", Local "Local file system at /tmp/rclone1815725417", Modify Window "1ms" --- PASS: TestSyncWithTrackRenamesStrategyModtime (5.08s) === RUN TestSyncWithTrackRenamesStrategyLeaf run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zedurer9kufu'", Local "Local file system at /tmp/rclone1815725417", Modify Window "1ms" sync_test.go:1649: Can track renames: true 2025/05/01 06:27:21 DEBUG : Added delayed dir = "sub", newDst= 2025/05/01 06:27:21 INFO : Encrypted drive 'TestCryptDrive:rclone-test-zedurer9kufu': Making map for --track-renames 2025/05/01 06:27:21 INFO : Encrypted drive 'TestCryptDrive:rclone-test-zedurer9kufu': Finished making map for --track-renames 2025/05/01 06:27:21 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zedurer9kufu': Waiting for checks to finish 2025/05/01 06:27:21 DEBUG : potato: Need to transfer - No matching file found at Destination 2025/05/01 06:27:21 DEBUG : sub/yam: Need to transfer - No matching file found at Destination 2025/05/01 06:27:21 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zedurer9kufu': Waiting for renames to finish 2025/05/01 06:27:21 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zedurer9kufu': Waiting for transfers to finish 2025/05/01 06:27:23 DEBUG : potato: md5 = e63d36097b20259b0b18464cd5046255 OK 2025/05/01 06:27:23 INFO : potato: Copied (new) 2025/05/01 06:27:23 DEBUG : sub/yam: md5 = 91e4a08a7b0dc9e894753620b0b417f1 OK 2025/05/01 06:27:23 INFO : sub/yam: Copied (new) 2025/05/01 06:27:23 DEBUG : Waiting for deletions to finish 2025/05/01 06:27:24 INFO : sub: Set directory modification time (using DirSetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zedurer9kufu'", Local "Local file system at /tmp/rclone1815725417", Modify Window "1ms" 2025/05/01 06:27:25 DEBUG : potato: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/05/01 06:27:25 DEBUG : potato: Unchanged skipping 2025/05/01 06:27:25 INFO : sub: Set directory modification time (using SetModTime) 2025/05/01 06:27:25 DEBUG : Added delayed dir = "sub", newDst=sub 2025/05/01 06:27:25 INFO : Encrypted drive 'TestCryptDrive:rclone-test-zedurer9kufu': Making map for --track-renames 2025/05/01 06:27:25 INFO : Encrypted drive 'TestCryptDrive:rclone-test-zedurer9kufu': Finished making map for --track-renames 2025/05/01 06:27:25 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zedurer9kufu': Waiting for checks to finish 2025/05/01 06:27:25 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zedurer9kufu': Waiting for renames to finish 2025/05/01 06:27:26 INFO : sub/yam: Moved (server-side) to: yam 2025/05/01 06:27:26 INFO : yam: Renamed from "sub/yam" 2025/05/01 06:27:26 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zedurer9kufu': Waiting for transfers to finish 2025/05/01 06:27:26 DEBUG : Waiting for deletions to finish 2025/05/01 06:27:26 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zedurer9kufu'", Local "Local file system at /tmp/rclone1815725417", Modify Window "1ms" --- PASS: TestSyncWithTrackRenamesStrategyLeaf (9.15s) === RUN TestServerSideMoveLocal run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zedurer9kufu'", Local "Local file system at /tmp/rclone1815725417", Modify Window "1ms" 2025/05/01 06:27:30 DEBUG : Creating backend with remote "/tmp/rclone1815725417/dir1" 2025/05/01 06:27:30 DEBUG : Config file has changed externally - reloading 2025/05/01 06:27:30 DEBUG : Creating backend with remote "/tmp/rclone1815725417/dir2" 2025/05/01 06:27:30 DEBUG : Local file system at /tmp/rclone1815725417/dir2: Using server-side directory move 2025/05/01 06:27:30 INFO : Local file system at /tmp/rclone1815725417/dir2: Server side directory move failed - fallback to file moves: can't copy directory - destination already exists 2025/05/01 06:27:30 DEBUG : file1.txt: Need to transfer - File not found at Destination 2025/05/01 06:27:30 INFO : file1.txt: Moved (server-side) 2025/05/01 06:27:30 DEBUG : Local file system at /tmp/rclone1815725417/dir2: Waiting for checks to finish 2025/05/01 06:27:30 DEBUG : Local file system at /tmp/rclone1815725417/dir2: Waiting for transfers to finish --- PASS: TestServerSideMoveLocal (0.41s) === RUN TestMoveWithDeleteEmptySrcDirs run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zedurer9kufu'", Local "Local file system at /tmp/rclone1815725417", Modify Window "1ms" 2025/05/01 06:27:31 DEBUG : Added delayed dir = "nested", newDst= 2025/05/01 06:27:31 DEBUG : Added delayed dir = "sub dir", newDst= 2025/05/01 06:27:31 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2025/05/01 06:27:31 DEBUG : Added delayed dir = "nested/sub dir", newDst= 2025/05/01 06:27:31 DEBUG : nested/sub dir/file: Need to transfer - File not found at Destination 2025/05/01 06:27:31 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zedurer9kufu': Waiting for checks to finish 2025/05/01 06:27:31 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zedurer9kufu': Waiting for transfers to finish 2025/05/01 06:27:33 DEBUG : sub dir/hello world: md5 = eef310ec441ce8221f4f6fc03981c183 OK 2025/05/01 06:27:33 INFO : sub dir/hello world: Copied (new) 2025/05/01 06:27:33 INFO : sub dir/hello world: Deleted 2025/05/01 06:27:35 DEBUG : nested/sub dir/file: md5 = faebe07c6097a212331e2996d17e7504 OK 2025/05/01 06:27:35 INFO : nested/sub dir/file: Copied (new) 2025/05/01 06:27:35 INFO : nested/sub dir/file: Deleted 2025/05/01 06:27:35 INFO : nested/sub dir: Set directory modification time (using DirSetModTime) 2025/05/01 06:27:36 INFO : nested: Set directory modification time (using DirSetModTime) 2025/05/01 06:27:36 INFO : sub dir: Set directory modification time (using DirSetModTime) 2025/05/01 06:27:36 INFO : sub dir: Removing directory 2025/05/01 06:27:36 INFO : nested/sub dir: Removing directory 2025/05/01 06:27:36 INFO : nested: Removing directory 2025/05/01 06:27:36 DEBUG : Local file system at /tmp/rclone1815725417: deleted 3 directories run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zedurer9kufu'", Local "Local file system at /tmp/rclone1815725417", Modify Window "1ms" 2025/05/01 06:27:38 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" 2025/05/01 06:27:39 DEBUG : 37qp6d1gohacv723ij3brofbu8/14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "ftp4kuv8se7tqduu6pmmcvjsmk" 2025/05/01 06:27:40 DEBUG : 37qp6d1gohacv723ij3brofbu8: Rmdir: contains trashed file: "14begaa36ih249fgrnfk6nulg0" --- PASS: TestMoveWithDeleteEmptySrcDirs (10.22s) === RUN TestMoveWithoutDeleteEmptySrcDirs run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zedurer9kufu'", Local "Local file system at /tmp/rclone1815725417", Modify Window "1ms" 2025/05/01 06:27:41 DEBUG : Added delayed dir = "nested", newDst= 2025/05/01 06:27:41 DEBUG : Added delayed dir = "sub dir", newDst= 2025/05/01 06:27:41 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2025/05/01 06:27:41 DEBUG : Added delayed dir = "nested/sub dir", newDst= 2025/05/01 06:27:41 DEBUG : nested/sub dir/file: Need to transfer - File not found at Destination 2025/05/01 06:27:41 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zedurer9kufu': Waiting for checks to finish 2025/05/01 06:27:41 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zedurer9kufu': Waiting for transfers to finish 2025/05/01 06:27:43 DEBUG : sub dir/hello world: md5 = 6d8faef0dcfd7997eecd94760ac52a19 OK 2025/05/01 06:27:43 INFO : sub dir/hello world: Copied (new) 2025/05/01 06:27:43 INFO : sub dir/hello world: Deleted 2025/05/01 06:27:45 DEBUG : nested/sub dir/file: md5 = 864d083823af9522c0f71c131fa72b49 OK 2025/05/01 06:27:45 INFO : nested/sub dir/file: Copied (new) 2025/05/01 06:27:45 INFO : nested/sub dir/file: Deleted 2025/05/01 06:27:45 INFO : nested/sub dir: Set directory modification time (using DirSetModTime) 2025/05/01 06:27:46 INFO : sub dir: Set directory modification time (using DirSetModTime) 2025/05/01 06:27:46 INFO : nested: Set directory modification time (using DirSetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zedurer9kufu'", Local "Local file system at /tmp/rclone1815725417", Modify Window "1ms" 2025/05/01 06:27:48 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" 2025/05/01 06:27:49 DEBUG : 37qp6d1gohacv723ij3brofbu8/14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "ftp4kuv8se7tqduu6pmmcvjsmk" 2025/05/01 06:27:50 DEBUG : 37qp6d1gohacv723ij3brofbu8: Rmdir: contains trashed file: "14begaa36ih249fgrnfk6nulg0" --- PASS: TestMoveWithoutDeleteEmptySrcDirs (10.13s) === RUN TestMoveWithIgnoreExisting run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zedurer9kufu'", Local "Local file system at /tmp/rclone1815725417", Modify Window "1ms" 2025/05/01 06:27:51 DEBUG : existing: Need to transfer - File not found at Destination 2025/05/01 06:27:51 DEBUG : existing-b: Need to transfer - File not found at Destination 2025/05/01 06:27:51 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zedurer9kufu': Waiting for checks to finish 2025/05/01 06:27:51 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zedurer9kufu': Waiting for transfers to finish 2025/05/01 06:27:52 DEBUG : existing-b: md5 = f4794942cf17730fa51d1c73e8260b0f OK 2025/05/01 06:27:52 INFO : existing-b: Copied (new) 2025/05/01 06:27:52 INFO : existing-b: Deleted 2025/05/01 06:27:52 DEBUG : existing: md5 = ca057bf7969a38f98f0bf575001df012 OK 2025/05/01 06:27:52 INFO : existing: Copied (new) 2025/05/01 06:27:52 INFO : existing: Deleted 2025/05/01 06:27:53 DEBUG : existing: Destination exists, skipping 2025/05/01 06:27:53 DEBUG : existing: Not removing source file as destination file exists and --ignore-existing is set 2025/05/01 06:27:53 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zedurer9kufu': Waiting for checks to finish 2025/05/01 06:27:53 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zedurer9kufu': Waiting for transfers to finish 2025/05/01 06:27:53 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zedurer9kufu'", Local "Local file system at /tmp/rclone1815725417", Modify Window "1ms" --- PASS: TestMoveWithIgnoreExisting (3.85s) === RUN TestServerSideMove run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zedurer9kufu'", Local "Local file system at /tmp/rclone1815725417", Modify Window "1ms" 2025/05/01 06:27:55 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-vayipex6doko" 2025/05/01 06:27:55 DEBUG : Config file has changed externally - reloading 2025/05/01 06:27:55 DEBUG : Creating backend with remote "TestDrive:crypt/toaaffltjmc660p1aiq07o87utvfr0g4s0564ds4nj0822m2vl30" 2025/05/01 06:27:57 DEBUG : potato2: md5 = 6d5dbd373d115764ada961c930aa9055 OK 2025/05/01 06:27:59 DEBUG : empty space: md5 = daf9e466d89d964509506d9e6eb65bf0 OK 2025/05/01 06:28:00 DEBUG : potato3: md5 = 8fa5e441e0421e9d2d9d8d653ce51f6d OK sync_test.go:1705: Server side move (if possible) Encrypted drive 'TestCryptDrive:rclone-test-zedurer9kufu' -> Encrypted drive 'TestCryptDrive:rclone-test-vayipex6doko' 2025/05/01 06:28:02 DEBUG : empty space: md5 = 08d4194cb282ab3928fa5e2276c07d62 OK 2025/05/01 06:28:04 DEBUG : potato3: md5 = d030c970880e868e9e6c10f02564562f OK 2025/05/01 06:28:04 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vayipex6doko': Using server-side directory move 2025/05/01 06:28:04 INFO : Encrypted drive 'TestCryptDrive:rclone-test-vayipex6doko': Server side directory move failed - fallback to file moves: can't copy directory - destination already exists 2025/05/01 06:28:04 DEBUG : potato2: Need to transfer - File not found at Destination 2025/05/01 06:28:04 DEBUG : empty space: Size and modification time the same (differ by 0s, within tolerance 1ms) 2025/05/01 06:28:04 DEBUG : empty space: Unchanged skipping 2025/05/01 06:28:04 DEBUG : potato3: Sizes differ (src 68 vs dst 60) 2025/05/01 06:28:04 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vayipex6doko': Waiting for checks to finish 2025/05/01 06:28:04 INFO : empty space: Deleted 2025/05/01 06:28:04 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vayipex6doko': Waiting for transfers to finish 2025/05/01 06:28:04 INFO : potato3: Deleted 2025/05/01 06:28:05 INFO : potato2: Moved (server-side) 2025/05/01 06:28:05 INFO : potato3: Moved (server-side) 2025/05/01 06:28:05 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-fowilax5yuce" 2025/05/01 06:28:06 DEBUG : Creating backend with remote "TestDrive:crypt/rg7ltn9h48ni1mojh9puim2j5uoqc7i14lumqa3296igorpppc0g" 2025/05/01 06:28:06 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-fowilax5yuce': Using server-side directory move 2025/05/01 06:28:07 INFO : Encrypted drive 'TestCryptDrive:rclone-test-fowilax5yuce': Server side directory move succeeded 2025/05/01 06:28:08 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-fowilax5yuce': Purge remote 2025/05/01 06:28:09 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vayipex6doko': Purge remote 2025/05/01 06:28:09 NOTICE: purge failed: directory not found --- PASS: TestServerSideMove (14.47s) === RUN TestServerSideMoveWithFilter run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zedurer9kufu'", Local "Local file system at /tmp/rclone1815725417", Modify Window "1ms" 2025/05/01 06:28:09 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-kipeqov0goko" 2025/05/01 06:28:09 DEBUG : Creating backend with remote "TestDrive:crypt/2ca5197c1hjhlol6dtbhke45ce19bmgdtb8k4m0vllo0660qruv0" 2025/05/01 06:28:12 DEBUG : potato2: md5 = f2b9901b0fd7dc4feb45722159575879 OK 2025/05/01 06:28:13 DEBUG : empty space: md5 = 32ec062d7f0498e3b7bcbe6db546a58f OK 2025/05/01 06:28:14 DEBUG : potato3: md5 = 6878dab908179623be60c391c81944a0 OK sync_test.go:1705: Server side move (if possible) Encrypted drive 'TestCryptDrive:rclone-test-zedurer9kufu' -> Encrypted drive 'TestCryptDrive:rclone-test-kipeqov0goko' 2025/05/01 06:28:17 DEBUG : empty space: md5 = 10cf021de0d57323d6acb2705b5612dd OK 2025/05/01 06:28:18 DEBUG : potato3: md5 = 0d49c103a7041d581053687c45c108fa OK 2025/05/01 06:28:18 DEBUG : empty space: Excluded (Size Filter) 2025/05/01 06:28:18 DEBUG : empty space: Excluded 2025/05/01 06:28:18 DEBUG : empty space: Excluded (Size Filter) 2025/05/01 06:28:18 DEBUG : empty space: Excluded 2025/05/01 06:28:18 DEBUG : potato2: Need to transfer - File not found at Destination 2025/05/01 06:28:18 DEBUG : potato3: Sizes differ (src 68 vs dst 60) 2025/05/01 06:28:18 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-kipeqov0goko': Waiting for checks to finish 2025/05/01 06:28:18 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-kipeqov0goko': Waiting for transfers to finish 2025/05/01 06:28:19 INFO : potato3: Deleted 2025/05/01 06:28:19 INFO : potato2: Moved (server-side) 2025/05/01 06:28:21 INFO : potato3: Moved (server-side) 2025/05/01 06:28:22 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-muvunok2lomo" 2025/05/01 06:28:22 DEBUG : Creating backend with remote "TestDrive:crypt/pt84827bf62drge5hb6k2udcbdue0ujh3e57cndu57fii88q0jo0" 2025/05/01 06:28:23 DEBUG : empty space: Excluded (Size Filter) 2025/05/01 06:28:23 DEBUG : empty space: Excluded 2025/05/01 06:28:23 DEBUG : potato2: Need to transfer - File not found at Destination 2025/05/01 06:28:23 DEBUG : potato3: Need to transfer - File not found at Destination 2025/05/01 06:28:23 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-muvunok2lomo': Waiting for checks to finish 2025/05/01 06:28:23 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-muvunok2lomo': Waiting for transfers to finish 2025/05/01 06:28:25 INFO : potato2: Moved (server-side) 2025/05/01 06:28:25 INFO : potato3: Moved (server-side) 2025/05/01 06:28:26 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-muvunok2lomo': Purge remote 2025/05/01 06:28:26 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-kipeqov0goko': Purge remote --- PASS: TestServerSideMoveWithFilter (18.49s) === RUN TestServerSideMoveDeleteEmptySourceDirs run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zedurer9kufu'", Local "Local file system at /tmp/rclone1815725417", Modify Window "1ms" 2025/05/01 06:28:28 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-kabuleq2vaju" 2025/05/01 06:28:28 DEBUG : Creating backend with remote "TestDrive:crypt/d0f3ibnv0k2maolc19vo7g4mnbei0gibtj73m2ruhqb8t6318rc0" 2025/05/01 06:28:30 DEBUG : potato2: md5 = c3c0b139285f83766a9e8b07eeb167d4 OK 2025/05/01 06:28:31 DEBUG : empty space: md5 = f20d5f4a9ba4fe199982a43b0a623612 OK 2025/05/01 06:28:33 DEBUG : potato3: md5 = 961f2c84e831471731ced993ccf1766b OK 2025/05/01 06:28:33 INFO : tomatoDir: Making directory sync_test.go:1705: Server side move (if possible) Encrypted drive 'TestCryptDrive:rclone-test-zedurer9kufu' -> Encrypted drive 'TestCryptDrive:rclone-test-kabuleq2vaju' 2025/05/01 06:28:36 DEBUG : empty space: md5 = 5f37fff26b20ac1f42eb88faac6d032e OK 2025/05/01 06:28:37 DEBUG : potato3: md5 = 15cd834eb611269f81c30d51120314c1 OK 2025/05/01 06:28:37 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-kabuleq2vaju': Using server-side directory move 2025/05/01 06:28:37 INFO : Encrypted drive 'TestCryptDrive:rclone-test-kabuleq2vaju': Server side directory move failed - fallback to file moves: can't copy directory - destination already exists 2025/05/01 06:28:38 DEBUG : potato2: Need to transfer - File not found at Destination 2025/05/01 06:28:38 DEBUG : Added delayed dir = "tomatoDir", newDst= 2025/05/01 06:28:38 DEBUG : empty space: Size and modification time the same (differ by 0s, within tolerance 1ms) 2025/05/01 06:28:38 DEBUG : potato3: Sizes differ (src 68 vs dst 60) 2025/05/01 06:28:38 DEBUG : empty space: Unchanged skipping 2025/05/01 06:28:38 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-kabuleq2vaju': Waiting for checks to finish 2025/05/01 06:28:38 INFO : potato3: Deleted 2025/05/01 06:28:38 INFO : empty space: Deleted 2025/05/01 06:28:38 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-kabuleq2vaju': Waiting for transfers to finish 2025/05/01 06:28:38 INFO : potato2: Moved (server-side) 2025/05/01 06:28:39 INFO : potato3: Moved (server-side) 2025/05/01 06:28:39 INFO : tomatoDir: Removing directory 2025/05/01 06:28:39 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zedurer9kufu': deleted 1 directories 2025/05/01 06:28:40 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-rekesan6gawu" 2025/05/01 06:28:40 DEBUG : Creating backend with remote "TestDrive:crypt/3d6hibr9175dsadmjfe8ppul3p5n86o1fji247aqhpbnovq0nrcg" 2025/05/01 06:28:41 INFO : tomatoDir: Making directory 2025/05/01 06:28:42 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-rekesan6gawu': Using server-side directory move 2025/05/01 06:28:42 INFO : Encrypted drive 'TestCryptDrive:rclone-test-rekesan6gawu': Server side directory move succeeded 2025/05/01 06:28:44 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-rekesan6gawu': Purge remote 2025/05/01 06:28:44 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-kabuleq2vaju': Purge remote 2025/05/01 06:28:44 NOTICE: purge failed: directory not found --- PASS: TestServerSideMoveDeleteEmptySourceDirs (17.19s) === RUN TestServerSideMoveOverlap run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zedurer9kufu'", Local "Local file system at /tmp/rclone1815725417", Modify Window "1ms" sync_test.go:1910: Skipping test as remote supports DirMove --- SKIP: TestServerSideMoveOverlap (0.43s) === RUN TestSyncOverlap run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zedurer9kufu'", Local "Local file system at /tmp/rclone1815725417", Modify Window "1ms" 2025/05/01 06:28:45 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-zedurer9kufu/rclone-sync-test" 2025/05/01 06:28:45 DEBUG : Creating backend with remote "TestDrive:crypt/8qbvuohkaa3egsv9bvujjbl2eclmttfbdc6hgn8m0s7jo9antms0/i7355aa0sb89uagn75vfjqr6s3e3e1h2et8in57abn1fe8qfego0" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zedurer9kufu'", Local "Local file system at /tmp/rclone1815725417", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zedurer9kufu'", Local "Local file system at /tmp/rclone1815725417", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zedurer9kufu'", Local "Local file system at /tmp/rclone1815725417", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zedurer9kufu'", Local "Local file system at /tmp/rclone1815725417", Modify Window "1ms" --- PASS: TestSyncOverlap (3.67s) === RUN TestSyncOverlapWithFilter run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zedurer9kufu'", Local "Local file system at /tmp/rclone1815725417", Modify Window "1ms" 2025/05/01 06:28:49 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-zedurer9kufu/rclone-sync-test" 2025/05/01 06:28:49 DEBUG : Creating backend with remote "TestDrive:crypt/8qbvuohkaa3egsv9bvujjbl2eclmttfbdc6hgn8m0s7jo9antms0/i7355aa0sb89uagn75vfjqr6s3e3e1h2et8in57abn1fe8qfego0" 2025/05/01 06:28:51 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-zedurer9kufu/rclone-sync-test-include/layer2" 2025/05/01 06:28:51 DEBUG : Creating backend with remote "TestDrive:crypt/8qbvuohkaa3egsv9bvujjbl2eclmttfbdc6hgn8m0s7jo9antms0/khf2vlblvnbf9ftevqm0htmss73hj1j5a7q328e4ohrgs7e2loe0/n01jpl9202nn9ec1rb75h0f1c4" 2025/05/01 06:28:54 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-zedurer9kufu/rclone-sync-test-ignore-file" 2025/05/01 06:28:54 DEBUG : Creating backend with remote "TestDrive:crypt/8qbvuohkaa3egsv9bvujjbl2eclmttfbdc6hgn8m0s7jo9antms0/kmf11jujl9uha3tjganvgpkn45bu778hb5vb5riug1c26b38k7sg" 2025/05/01 06:28:58 DEBUG : rclone-sync-test-ignore-file/.ignore: md5 = 115666ac2fcede59b519cf5aab3c45b2 OK 2025/05/01 06:28:59 DEBUG : rclone-sync-test-ignore-file: Excluded 2025/05/01 06:28:59 DEBUG : rclone-sync-test: Excluded 2025/05/01 06:28:59 DEBUG : Added delayed dir = "rclone-sync-test-include", newDst= 2025/05/01 06:29:00 DEBUG : rclone-sync-test-include/layer2: Excluded 2025/05/01 06:29:00 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zedurer9kufu/rclone-sync-test': Waiting for checks to finish 2025/05/01 06:29:00 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zedurer9kufu/rclone-sync-test': Waiting for transfers to finish 2025/05/01 06:29:00 DEBUG : Waiting for deletions to finish 2025/05/01 06:29:00 INFO : There was nothing to transfer 2025/05/01 06:29:00 DEBUG : rclone-sync-test-ignore-file: Excluded 2025/05/01 06:29:01 DEBUG : rclone-sync-test: Excluded 2025/05/01 06:29:01 DEBUG : rclone-sync-test-include/layer2: Excluded 2025/05/01 06:29:01 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zedurer9kufu': Waiting for checks to finish 2025/05/01 06:29:01 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zedurer9kufu': Waiting for transfers to finish 2025/05/01 06:29:01 DEBUG : Waiting for deletions to finish 2025/05/01 06:29:01 INFO : rclone-sync-test-include: Removing directory 2025/05/01 06:29:01 DEBUG : khf2vlblvnbf9ftevqm0htmss73hj1j5a7q328e4ohrgs7e2loe0: Rmdir: contains file: "n01jpl9202nn9ec1rb75h0f1c4" 2025/05/01 06:29:01 DEBUG : rclone-sync-test-include: Failed to Rmdir: directory not empty 2025/05/01 06:29:01 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zedurer9kufu': failed to delete 1 directories 2025/05/01 06:29:01 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zedurer9kufu'", Local "Local file system at /tmp/rclone1815725417", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zedurer9kufu'", Local "Local file system at /tmp/rclone1815725417", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zedurer9kufu'", Local "Local file system at /tmp/rclone1815725417", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zedurer9kufu'", Local "Local file system at /tmp/rclone1815725417", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zedurer9kufu'", Local "Local file system at /tmp/rclone1815725417", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zedurer9kufu'", Local "Local file system at /tmp/rclone1815725417", Modify Window "1ms" 2025/05/01 06:29:02 DEBUG : rclone-sync-test-ignore-file: Excluded 2025/05/01 06:29:03 DEBUG : rclone-sync-test: Excluded 2025/05/01 06:29:03 DEBUG : Added delayed dir = "rclone-sync-test-include", newDst= 2025/05/01 06:29:03 DEBUG : rclone-sync-test-include/layer2: Excluded 2025/05/01 06:29:03 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zedurer9kufu/rclone-sync-test-include/layer2': Waiting for checks to finish 2025/05/01 06:29:03 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zedurer9kufu/rclone-sync-test-include/layer2': Waiting for transfers to finish 2025/05/01 06:29:03 DEBUG : Waiting for deletions to finish 2025/05/01 06:29:03 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zedurer9kufu'", Local "Local file system at /tmp/rclone1815725417", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zedurer9kufu'", Local "Local file system at /tmp/rclone1815725417", Modify Window "1ms" 2025/05/01 06:29:04 DEBUG : rclone-sync-test-ignore-file: Excluded 2025/05/01 06:29:04 DEBUG : rclone-sync-test: Excluded 2025/05/01 06:29:05 DEBUG : rclone-sync-test-include/layer2: Excluded 2025/05/01 06:29:05 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zedurer9kufu': Waiting for checks to finish 2025/05/01 06:29:05 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zedurer9kufu': Waiting for transfers to finish 2025/05/01 06:29:05 DEBUG : Waiting for deletions to finish 2025/05/01 06:29:05 INFO : rclone-sync-test-include: Removing directory 2025/05/01 06:29:05 DEBUG : khf2vlblvnbf9ftevqm0htmss73hj1j5a7q328e4ohrgs7e2loe0: Rmdir: contains file: "n01jpl9202nn9ec1rb75h0f1c4" 2025/05/01 06:29:05 DEBUG : rclone-sync-test-include: Failed to Rmdir: directory not empty 2025/05/01 06:29:05 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zedurer9kufu': failed to delete 1 directories 2025/05/01 06:29:05 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zedurer9kufu'", Local "Local file system at /tmp/rclone1815725417", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zedurer9kufu'", Local "Local file system at /tmp/rclone1815725417", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zedurer9kufu'", Local "Local file system at /tmp/rclone1815725417", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zedurer9kufu'", Local "Local file system at /tmp/rclone1815725417", Modify Window "1ms" 2025/05/01 06:29:05 DEBUG : : Excluded 2025/05/01 06:29:05 DEBUG : rclone-sync-test-ignore-file: Excluded 2025/05/01 06:29:06 DEBUG : rclone-sync-test: Excluded 2025/05/01 06:29:06 DEBUG : Added delayed dir = "rclone-sync-test-include", newDst= 2025/05/01 06:29:06 DEBUG : rclone-sync-test-include/layer2: Excluded 2025/05/01 06:29:06 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zedurer9kufu/rclone-sync-test-ignore-file': Waiting for checks to finish 2025/05/01 06:29:06 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zedurer9kufu/rclone-sync-test-ignore-file': Waiting for transfers to finish 2025/05/01 06:29:06 DEBUG : Waiting for deletions to finish 2025/05/01 06:29:06 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zedurer9kufu'", Local "Local file system at /tmp/rclone1815725417", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zedurer9kufu'", Local "Local file system at /tmp/rclone1815725417", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zedurer9kufu'", Local "Local file system at /tmp/rclone1815725417", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zedurer9kufu'", Local "Local file system at /tmp/rclone1815725417", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zedurer9kufu'", Local "Local file system at /tmp/rclone1815725417", Modify Window "1ms" 2025/05/01 06:29:09 DEBUG : khf2vlblvnbf9ftevqm0htmss73hj1j5a7q328e4ohrgs7e2loe0: Rmdir: contains trashed file: "n01jpl9202nn9ec1rb75h0f1c4" 2025/05/01 06:29:09 DEBUG : kmf11jujl9uha3tjganvgpkn45bu778hb5vb5riug1c26b38k7sg: Rmdir: contains trashed file: "i0t74httmdlljg425j6tg570d8" --- PASS: TestSyncOverlapWithFilter (29.20s) === RUN TestSyncCompareDest run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zedurer9kufu'", Local "Local file system at /tmp/rclone1815725417", Modify Window "1ms" 2025/05/01 06:29:18 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-zedurer9kufu/dst" 2025/05/01 06:29:18 DEBUG : Creating backend with remote "TestDrive:crypt/8qbvuohkaa3egsv9bvujjbl2eclmttfbdc6hgn8m0s7jo9antms0/31u3jie661vd5p8j7rtc3hgbh0" 2025/05/01 06:29:20 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-zedurer9kufu/CompareDest" 2025/05/01 06:29:20 DEBUG : Creating backend with remote "TestDrive:crypt/8qbvuohkaa3egsv9bvujjbl2eclmttfbdc6hgn8m0s7jo9antms0/gveqi14airsml4bgu7krj116o8" 2025/05/01 06:29:21 DEBUG : one: Need to transfer - File not found at Destination 2025/05/01 06:29:21 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zedurer9kufu/dst': Waiting for checks to finish 2025/05/01 06:29:21 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zedurer9kufu/dst': Waiting for transfers to finish 2025/05/01 06:29:23 DEBUG : one: md5 = 922a585173b19f58e32a38b07a7efe62 OK 2025/05/01 06:29:23 INFO : one: Copied (new) 2025/05/01 06:29:23 DEBUG : Waiting for deletions to finish 2025/05/01 06:29:25 DEBUG : one: Sizes differ (src 5 vs dst 3) 2025/05/01 06:29:25 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zedurer9kufu/dst': Waiting for checks to finish 2025/05/01 06:29:25 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zedurer9kufu/dst': Waiting for transfers to finish 2025/05/01 06:29:26 DEBUG : one: md5 = 248acd151d82ce74317f31687f6fbfd7 OK 2025/05/01 06:29:26 INFO : one: Copied (replaced existing) 2025/05/01 06:29:26 DEBUG : Waiting for deletions to finish 2025/05/01 06:29:28 DEBUG : dst/one: md5 = ea8d8a1736975784ed2e6ec4c81cdcee OK 2025/05/01 06:29:30 DEBUG : CompareDest/one: md5 = 23d98e6460a4fa58bddc99c99db92fda OK 2025/05/01 06:29:31 DEBUG : one: Sizes differ (src 5 vs dst 3) 2025/05/01 06:29:31 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zedurer9kufu/dst': Waiting for checks to finish 2025/05/01 06:29:31 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/05/01 06:29:31 DEBUG : one: Destination found in --compare-dest, skipping 2025/05/01 06:29:31 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zedurer9kufu/dst': Waiting for transfers to finish 2025/05/01 06:29:31 DEBUG : Waiting for deletions to finish 2025/05/01 06:29:31 INFO : There was nothing to transfer 2025/05/01 06:29:33 DEBUG : CompareDest/two: md5 = 3a8c9c11e2bdd789868a45f29d3c6775 OK 2025/05/01 06:29:34 DEBUG : one: Sizes differ (src 5 vs dst 3) 2025/05/01 06:29:34 DEBUG : two: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/05/01 06:29:34 DEBUG : two: Destination found in --compare-dest, skipping 2025/05/01 06:29:34 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zedurer9kufu/dst': Waiting for checks to finish 2025/05/01 06:29:34 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/05/01 06:29:34 DEBUG : one: Destination found in --compare-dest, skipping 2025/05/01 06:29:34 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zedurer9kufu/dst': Waiting for transfers to finish 2025/05/01 06:29:34 DEBUG : Waiting for deletions to finish 2025/05/01 06:29:34 INFO : There was nothing to transfer 2025/05/01 06:29:34 DEBUG : one: Sizes differ (src 5 vs dst 3) 2025/05/01 06:29:35 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/05/01 06:29:35 DEBUG : one: Destination found in --compare-dest, skipping 2025/05/01 06:29:35 DEBUG : two: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/05/01 06:29:35 DEBUG : two: Destination found in --compare-dest, skipping 2025/05/01 06:29:35 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zedurer9kufu/dst': Waiting for checks to finish 2025/05/01 06:29:35 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zedurer9kufu/dst': Waiting for transfers to finish 2025/05/01 06:29:35 DEBUG : Waiting for deletions to finish 2025/05/01 06:29:35 INFO : There was nothing to transfer sync_test.go:2175: No hash on uploaded file so skipping compare timestamp test 2025/05/01 06:29:36 DEBUG : one: Sizes differ (src 5 vs dst 3) 2025/05/01 06:29:36 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/05/01 06:29:36 DEBUG : one: Destination found in --compare-dest, skipping 2025/05/01 06:29:36 DEBUG : two: Sizes differ (src 5 vs dst 3) 2025/05/01 06:29:36 DEBUG : two: Need to transfer - File not found at Destination 2025/05/01 06:29:36 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zedurer9kufu/dst': Waiting for checks to finish 2025/05/01 06:29:36 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zedurer9kufu/dst': Waiting for transfers to finish 2025/05/01 06:29:37 DEBUG : two: md5 = b03e2355f3a28b7ef80975decefa7058 OK 2025/05/01 06:29:37 INFO : two: Copied (new) 2025/05/01 06:29:37 DEBUG : Waiting for deletions to finish 2025/05/01 06:29:40 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k" 2025/05/01 06:29:40 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" 2025/05/01 06:29:41 DEBUG : gveqi14airsml4bgu7krj116o8: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k" 2025/05/01 06:29:41 DEBUG : gveqi14airsml4bgu7krj116o8: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" --- PASS: TestSyncCompareDest (23.52s) === RUN TestSyncMultipleCompareDest run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zedurer9kufu'", Local "Local file system at /tmp/rclone1815725417", Modify Window "1ms" 2025/05/01 06:29:44 DEBUG : pre-dest1/1: md5 = d541ac964c34591450b27fe33d00b510 OK 2025/05/01 06:29:46 DEBUG : pre-dest2/2: md5 = 7324eda9b6ebc03fa2fceb6ed056d7e5 OK 2025/05/01 06:29:46 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-zedurer9kufu/dest" 2025/05/01 06:29:46 DEBUG : Creating backend with remote "TestDrive:crypt/8qbvuohkaa3egsv9bvujjbl2eclmttfbdc6hgn8m0s7jo9antms0/rg03c1jvnehrrc617i0lnqjddc" 2025/05/01 06:29:48 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-zedurer9kufu/pre-dest1" 2025/05/01 06:29:48 DEBUG : Creating backend with remote "TestDrive:crypt/8qbvuohkaa3egsv9bvujjbl2eclmttfbdc6hgn8m0s7jo9antms0/bbnblvh6k061ssopqrp18kd7gc" 2025/05/01 06:29:49 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-zedurer9kufu/pre-dest2" 2025/05/01 06:29:49 DEBUG : Creating backend with remote "TestDrive:crypt/8qbvuohkaa3egsv9bvujjbl2eclmttfbdc6hgn8m0s7jo9antms0/dgicm1h6b5ejvlltm8eeif0bnk" 2025/05/01 06:29:50 DEBUG : 1: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/05/01 06:29:50 DEBUG : 1: Destination found in --compare-dest, skipping 2025/05/01 06:29:50 DEBUG : 2: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/05/01 06:29:50 DEBUG : 2: Destination found in --compare-dest, skipping 2025/05/01 06:29:51 DEBUG : 3: Need to transfer - File not found at Destination 2025/05/01 06:29:51 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zedurer9kufu/dest': Waiting for checks to finish 2025/05/01 06:29:51 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zedurer9kufu/dest': Waiting for transfers to finish 2025/05/01 06:29:53 DEBUG : 3: md5 = 683e87039d18e2d3efc4acf425345eed OK 2025/05/01 06:29:53 INFO : 3: Copied (new) 2025/05/01 06:29:53 DEBUG : Waiting for deletions to finish 2025/05/01 06:29:55 DEBUG : dgicm1h6b5ejvlltm8eeif0bnk: Rmdir: contains trashed file: "1ghu8geql9vrl726n32nrf65bc" 2025/05/01 06:29:56 DEBUG : bbnblvh6k061ssopqrp18kd7gc: Rmdir: contains trashed file: "skbfko3oil7es0lj68ob574sro" 2025/05/01 06:29:57 DEBUG : rg03c1jvnehrrc617i0lnqjddc: Rmdir: contains trashed file: "g072p7hmjchlnj0gibe64c1epg" --- PASS: TestSyncMultipleCompareDest (15.60s) === RUN TestSyncCopyDest run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zedurer9kufu'", Local "Local file system at /tmp/rclone1815725417", Modify Window "1ms" 2025/05/01 06:29:57 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-zedurer9kufu/dst" 2025/05/01 06:29:57 DEBUG : Creating backend with remote "TestDrive:crypt/8qbvuohkaa3egsv9bvujjbl2eclmttfbdc6hgn8m0s7jo9antms0/31u3jie661vd5p8j7rtc3hgbh0" 2025/05/01 06:29:59 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-zedurer9kufu/CopyDest" 2025/05/01 06:29:59 DEBUG : Creating backend with remote "TestDrive:crypt/8qbvuohkaa3egsv9bvujjbl2eclmttfbdc6hgn8m0s7jo9antms0/d09o6po3f7bm6ce32vdgs8h9ls" 2025/05/01 06:30:01 DEBUG : one: Need to transfer - File not found at Destination 2025/05/01 06:30:01 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zedurer9kufu/dst': Waiting for checks to finish 2025/05/01 06:30:01 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zedurer9kufu/dst': Waiting for transfers to finish 2025/05/01 06:30:03 DEBUG : one: md5 = 238bfb0dd4529e6aaba8ca3fed2df45c OK 2025/05/01 06:30:03 INFO : one: Copied (new) 2025/05/01 06:30:03 DEBUG : Waiting for deletions to finish 2025/05/01 06:30:04 DEBUG : one: Sizes differ (src 5 vs dst 3) 2025/05/01 06:30:04 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zedurer9kufu/dst': Waiting for checks to finish 2025/05/01 06:30:04 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zedurer9kufu/dst': Waiting for transfers to finish 2025/05/01 06:30:05 DEBUG : one: md5 = b1059465e941038fa294bb4c05da88eb OK 2025/05/01 06:30:05 INFO : one: Copied (replaced existing) 2025/05/01 06:30:05 DEBUG : Waiting for deletions to finish 2025/05/01 06:30:07 DEBUG : dst/one: md5 = 053f3f6e474ec7fa523b9c61f07abea6 OK 2025/05/01 06:30:09 DEBUG : CopyDest/one: md5 = e4befc50f56187e0bd82508b374beaa2 OK 2025/05/01 06:30:10 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-zedurer9kufu/BackupDir" 2025/05/01 06:30:10 DEBUG : Creating backend with remote "TestDrive:crypt/8qbvuohkaa3egsv9bvujjbl2eclmttfbdc6hgn8m0s7jo9antms0/s6dbk3lfi7c9kfvo6j7bla9m0g" 2025/05/01 06:30:11 DEBUG : one: Sizes differ (src 5 vs dst 3) 2025/05/01 06:30:11 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zedurer9kufu/dst': Waiting for checks to finish 2025/05/01 06:30:12 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/05/01 06:30:12 DEBUG : one: Sizes differ (src 5 vs dst 3) 2025/05/01 06:30:14 INFO : one: Moved (server-side) 2025/05/01 06:30:15 INFO : one: Copied (server-side copy) 2025/05/01 06:30:15 DEBUG : one: Destination found in --copy-dest, using server-side copy 2025/05/01 06:30:15 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zedurer9kufu/dst': Waiting for transfers to finish 2025/05/01 06:30:15 DEBUG : Waiting for deletions to finish 2025/05/01 06:30:17 DEBUG : CopyDest/two: md5 = 4782458227fc5ac32eaa04c95932d038 OK 2025/05/01 06:30:17 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/05/01 06:30:17 DEBUG : one: Unchanged skipping 2025/05/01 06:30:18 DEBUG : two: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/05/01 06:30:19 INFO : two: Copied (server-side copy) 2025/05/01 06:30:19 DEBUG : two: Destination found in --copy-dest, using server-side copy 2025/05/01 06:30:19 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zedurer9kufu/dst': Waiting for checks to finish 2025/05/01 06:30:19 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zedurer9kufu/dst': Waiting for transfers to finish 2025/05/01 06:30:19 DEBUG : Waiting for deletions to finish 2025/05/01 06:30:19 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/05/01 06:30:19 DEBUG : one: Unchanged skipping 2025/05/01 06:30:19 DEBUG : two: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/05/01 06:30:19 DEBUG : two: Unchanged skipping 2025/05/01 06:30:19 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zedurer9kufu/dst': Waiting for checks to finish 2025/05/01 06:30:19 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zedurer9kufu/dst': Waiting for transfers to finish 2025/05/01 06:30:19 DEBUG : Waiting for deletions to finish 2025/05/01 06:30:19 INFO : There was nothing to transfer 2025/05/01 06:30:21 DEBUG : CopyDest/three: md5 = 64955441ebac2570b85dee0aba085bf1 OK 2025/05/01 06:30:22 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/05/01 06:30:22 DEBUG : one: Unchanged skipping 2025/05/01 06:30:22 DEBUG : three: Sizes differ (src 7 vs dst 5) 2025/05/01 06:30:22 DEBUG : three: Destination not found in --copy-dest 2025/05/01 06:30:22 DEBUG : three: Need to transfer - File not found at Destination 2025/05/01 06:30:22 DEBUG : two: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/05/01 06:30:22 DEBUG : two: Unchanged skipping 2025/05/01 06:30:22 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zedurer9kufu/dst': Waiting for checks to finish 2025/05/01 06:30:22 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zedurer9kufu/dst': Waiting for transfers to finish 2025/05/01 06:30:23 DEBUG : three: md5 = 192d7a6ec25a2acceb365063fd1d35e0 OK 2025/05/01 06:30:23 INFO : three: Copied (new) 2025/05/01 06:30:23 DEBUG : Waiting for deletions to finish 2025/05/01 06:30:28 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "b6jdmn2b1adrhc8vikh7edr9os" 2025/05/01 06:30:28 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k" 2025/05/01 06:30:28 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" 2025/05/01 06:30:29 DEBUG : d09o6po3f7bm6ce32vdgs8h9ls: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" 2025/05/01 06:30:29 DEBUG : d09o6po3f7bm6ce32vdgs8h9ls: Rmdir: contains trashed file: "b6jdmn2b1adrhc8vikh7edr9os" 2025/05/01 06:30:29 DEBUG : d09o6po3f7bm6ce32vdgs8h9ls: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k" 2025/05/01 06:30:29 DEBUG : s6dbk3lfi7c9kfvo6j7bla9m0g: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" --- PASS: TestSyncCopyDest (32.74s) === RUN TestSyncBackupDir run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zedurer9kufu'", Local "Local file system at /tmp/rclone1815725417", Modify Window "1ms" 2025/05/01 06:30:32 DEBUG : dst/one: md5 = e0c09a689eb25ba75c3466133134fcf8 OK 2025/05/01 06:30:34 DEBUG : dst/two: md5 = a8062efcdf37b2705e8d9fb5bf89e400 OK 2025/05/01 06:30:35 DEBUG : dst/three.txt: md5 = 47be743dc1d3ba76611b47ac4ddb4825 OK 2025/05/01 06:30:35 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-zedurer9kufu/dst" 2025/05/01 06:30:35 DEBUG : Creating backend with remote "TestDrive:crypt/8qbvuohkaa3egsv9bvujjbl2eclmttfbdc6hgn8m0s7jo9antms0/31u3jie661vd5p8j7rtc3hgbh0" 2025/05/01 06:30:36 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-zedurer9kufu/backup" 2025/05/01 06:30:36 DEBUG : Creating backend with remote "TestDrive:crypt/8qbvuohkaa3egsv9bvujjbl2eclmttfbdc6hgn8m0s7jo9antms0/1nrff024r7pq65ecp72fc28jb0" 2025/05/01 06:30:38 DEBUG : one: Sizes differ (src 4 vs dst 3) 2025/05/01 06:30:38 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/05/01 06:30:38 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zedurer9kufu/dst': Waiting for checks to finish 2025/05/01 06:30:38 DEBUG : two: Unchanged skipping 2025/05/01 06:30:39 INFO : one: Moved (server-side) 2025/05/01 06:30:39 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zedurer9kufu/dst': Waiting for transfers to finish 2025/05/01 06:30:41 DEBUG : one: md5 = 4e470a59ed928c8ebf4985ace409876a OK 2025/05/01 06:30:41 INFO : one: Copied (new) 2025/05/01 06:30:41 DEBUG : Waiting for deletions to finish 2025/05/01 06:30:42 INFO : three.txt: Moved (server-side) 2025/05/01 06:30:42 INFO : three.txt: Moved into backup dir 2025/05/01 06:30:43 DEBUG : dst/three.txt: md5 = 56571e4b682a2daa8320a79c5527f097 OK 2025/05/01 06:30:44 DEBUG : one: Sizes differ (src 5 vs dst 4) 2025/05/01 06:30:44 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/05/01 06:30:44 DEBUG : two: Unchanged skipping 2025/05/01 06:30:44 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zedurer9kufu/dst': Waiting for checks to finish 2025/05/01 06:30:45 INFO : one: Deleted 2025/05/01 06:30:45 INFO : one: Moved (server-side) 2025/05/01 06:30:45 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zedurer9kufu/dst': Waiting for transfers to finish 2025/05/01 06:30:47 DEBUG : one: md5 = 5694a24bcee65f39383fecc319e05c85 OK 2025/05/01 06:30:47 INFO : one: Copied (new) 2025/05/01 06:30:47 DEBUG : Waiting for deletions to finish 2025/05/01 06:30:47 INFO : three.txt: Deleted 2025/05/01 06:30:48 INFO : three.txt: Moved (server-side) 2025/05/01 06:30:48 INFO : three.txt: Moved into backup dir 2025/05/01 06:30:51 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" 2025/05/01 06:30:51 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k" 2025/05/01 06:30:52 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "tr2hj63d80ftlmvm6a952snjcc" 2025/05/01 06:30:52 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" 2025/05/01 06:30:52 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" 2025/05/01 06:30:52 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "tr2hj63d80ftlmvm6a952snjcc" --- PASS: TestSyncBackupDir (22.31s) === RUN TestSyncBackupDirWithSuffix run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zedurer9kufu'", Local "Local file system at /tmp/rclone1815725417", Modify Window "1ms" 2025/05/01 06:30:55 DEBUG : dst/one: md5 = f3360db6cd39c3b17754109acd5f20db OK 2025/05/01 06:30:56 DEBUG : dst/two: md5 = 48130209924ad0042f2b7d4b569f00fa OK 2025/05/01 06:30:57 DEBUG : dst/three.txt: md5 = 774f14d5544ba44cc192aec70c84c47b OK 2025/05/01 06:30:58 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-zedurer9kufu/dst" 2025/05/01 06:30:58 DEBUG : Creating backend with remote "TestDrive:crypt/8qbvuohkaa3egsv9bvujjbl2eclmttfbdc6hgn8m0s7jo9antms0/31u3jie661vd5p8j7rtc3hgbh0" 2025/05/01 06:30:58 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-zedurer9kufu/backup" 2025/05/01 06:30:59 DEBUG : Creating backend with remote "TestDrive:crypt/8qbvuohkaa3egsv9bvujjbl2eclmttfbdc6hgn8m0s7jo9antms0/1nrff024r7pq65ecp72fc28jb0" 2025/05/01 06:31:00 DEBUG : one: Sizes differ (src 4 vs dst 3) 2025/05/01 06:31:00 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/05/01 06:31:00 DEBUG : two: Unchanged skipping 2025/05/01 06:31:00 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zedurer9kufu/dst': Waiting for checks to finish 2025/05/01 06:31:02 INFO : one: Moved (server-side) to: one.bak 2025/05/01 06:31:02 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zedurer9kufu/dst': Waiting for transfers to finish 2025/05/01 06:31:03 DEBUG : one: md5 = 880442864be9ce7df2e2a10878fb4bbb OK 2025/05/01 06:31:03 INFO : one: Copied (new) 2025/05/01 06:31:03 DEBUG : Waiting for deletions to finish 2025/05/01 06:31:04 INFO : three.txt: Moved (server-side) to: three.txt.bak 2025/05/01 06:31:04 INFO : three.txt: Moved into backup dir 2025/05/01 06:31:06 DEBUG : dst/three.txt: md5 = a7ee16a0bcbca956ead821690d589711 OK 2025/05/01 06:31:06 DEBUG : one: Sizes differ (src 5 vs dst 4) 2025/05/01 06:31:06 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/05/01 06:31:06 DEBUG : two: Unchanged skipping 2025/05/01 06:31:06 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zedurer9kufu/dst': Waiting for checks to finish 2025/05/01 06:31:07 INFO : one.bak: Deleted 2025/05/01 06:31:08 INFO : one: Moved (server-side) to: one.bak 2025/05/01 06:31:08 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zedurer9kufu/dst': Waiting for transfers to finish 2025/05/01 06:31:09 DEBUG : one: md5 = 3a8ee0bd241b3a36c852e43369c0c368 OK 2025/05/01 06:31:09 INFO : one: Copied (new) 2025/05/01 06:31:09 DEBUG : Waiting for deletions to finish 2025/05/01 06:31:09 INFO : three.txt.bak: Deleted 2025/05/01 06:31:10 INFO : three.txt: Moved (server-side) to: three.txt.bak 2025/05/01 06:31:10 INFO : three.txt: Moved into backup dir 2025/05/01 06:31:13 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" 2025/05/01 06:31:13 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k" 2025/05/01 06:31:14 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "sk91qgsqfn0r271r2ehsaoc20c" 2025/05/01 06:31:14 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "qltcak2uaegtmcoa8vijdppbp8" 2025/05/01 06:31:14 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "qltcak2uaegtmcoa8vijdppbp8" 2025/05/01 06:31:14 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "sk91qgsqfn0r271r2ehsaoc20c" --- PASS: TestSyncBackupDirWithSuffix (22.27s) === RUN TestSyncBackupDirWithSuffixKeepExtension run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zedurer9kufu'", Local "Local file system at /tmp/rclone1815725417", Modify Window "1ms" 2025/05/01 06:31:17 DEBUG : dst/one: md5 = 06241a4f9117e5287bf041cdb312d44e OK 2025/05/01 06:31:18 DEBUG : dst/two: md5 = 1ad900f8c8efae23a80f21d880d88602 OK 2025/05/01 06:31:20 DEBUG : dst/three.txt: md5 = adcd5ec285240568e9e409a4021d4ef4 OK 2025/05/01 06:31:20 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-zedurer9kufu/dst" 2025/05/01 06:31:20 DEBUG : Creating backend with remote "TestDrive:crypt/8qbvuohkaa3egsv9bvujjbl2eclmttfbdc6hgn8m0s7jo9antms0/31u3jie661vd5p8j7rtc3hgbh0" 2025/05/01 06:31:21 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-zedurer9kufu/backup" 2025/05/01 06:31:21 DEBUG : Creating backend with remote "TestDrive:crypt/8qbvuohkaa3egsv9bvujjbl2eclmttfbdc6hgn8m0s7jo9antms0/1nrff024r7pq65ecp72fc28jb0" 2025/05/01 06:31:22 DEBUG : one: Sizes differ (src 4 vs dst 3) 2025/05/01 06:31:22 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/05/01 06:31:22 DEBUG : two: Unchanged skipping 2025/05/01 06:31:22 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zedurer9kufu/dst': Waiting for checks to finish 2025/05/01 06:31:24 INFO : one: Moved (server-side) to: one-2019-01-01 2025/05/01 06:31:24 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zedurer9kufu/dst': Waiting for transfers to finish 2025/05/01 06:31:25 DEBUG : one: md5 = a7e1934ebdaeb6c69e4ce5ce9c82aa7f OK 2025/05/01 06:31:25 INFO : one: Copied (new) 2025/05/01 06:31:25 DEBUG : Waiting for deletions to finish 2025/05/01 06:31:26 INFO : three.txt: Moved (server-side) to: three-2019-01-01.txt 2025/05/01 06:31:26 INFO : three.txt: Moved into backup dir 2025/05/01 06:31:28 DEBUG : dst/three.txt: md5 = 292c596c74b4bf3ad9a269a2f677ff0f OK 2025/05/01 06:31:29 DEBUG : one: Sizes differ (src 5 vs dst 4) 2025/05/01 06:31:29 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/05/01 06:31:29 DEBUG : two: Unchanged skipping 2025/05/01 06:31:29 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zedurer9kufu/dst': Waiting for checks to finish 2025/05/01 06:31:30 INFO : one-2019-01-01: Deleted 2025/05/01 06:31:30 INFO : one: Moved (server-side) to: one-2019-01-01 2025/05/01 06:31:30 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zedurer9kufu/dst': Waiting for transfers to finish 2025/05/01 06:31:31 DEBUG : one: md5 = 878b0b14f28c600b0feb65d53ccbc699 OK 2025/05/01 06:31:31 INFO : one: Copied (new) 2025/05/01 06:31:31 DEBUG : Waiting for deletions to finish 2025/05/01 06:31:32 INFO : three-2019-01-01.txt: Deleted 2025/05/01 06:31:33 INFO : three.txt: Moved (server-side) to: three-2019-01-01.txt 2025/05/01 06:31:33 INFO : three.txt: Moved into backup dir 2025/05/01 06:31:36 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" 2025/05/01 06:31:36 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k" 2025/05/01 06:31:37 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "qtq2f6qq4lgpsmj88vb7147qje3prudmtfdtr2342fth58vo9a50" 2025/05/01 06:31:37 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "jcjl1bv3ep0v8kt35lqql1co90" 2025/05/01 06:31:37 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "jcjl1bv3ep0v8kt35lqql1co90" 2025/05/01 06:31:37 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "qtq2f6qq4lgpsmj88vb7147qje3prudmtfdtr2342fth58vo9a50" --- PASS: TestSyncBackupDirWithSuffixKeepExtension (22.58s) === RUN TestSyncBackupDirSuffixOnly run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zedurer9kufu'", Local "Local file system at /tmp/rclone1815725417", Modify Window "1ms" 2025/05/01 06:31:39 DEBUG : dst/one: md5 = 7c10310003a370a8eded80c8faad4f75 OK 2025/05/01 06:31:41 DEBUG : dst/two: md5 = dda544abf26c7dd89c516d6079d345e1 OK 2025/05/01 06:31:42 DEBUG : dst/three.txt: md5 = 10bb05c7e843c9817e15a0c00b8317ca OK 2025/05/01 06:31:43 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-zedurer9kufu/dst" 2025/05/01 06:31:43 DEBUG : Creating backend with remote "TestDrive:crypt/8qbvuohkaa3egsv9bvujjbl2eclmttfbdc6hgn8m0s7jo9antms0/31u3jie661vd5p8j7rtc3hgbh0" 2025/05/01 06:31:44 DEBUG : one: Sizes differ (src 4 vs dst 3) 2025/05/01 06:31:44 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/05/01 06:31:44 DEBUG : two: Unchanged skipping 2025/05/01 06:31:44 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zedurer9kufu/dst': Waiting for checks to finish 2025/05/01 06:31:44 INFO : one: Moved (server-side) to: one.bak 2025/05/01 06:31:44 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zedurer9kufu/dst': Waiting for transfers to finish 2025/05/01 06:31:46 DEBUG : one: md5 = 6725d943ecb8673703071efa5f6292ba OK 2025/05/01 06:31:46 INFO : one: Copied (new) 2025/05/01 06:31:46 DEBUG : Waiting for deletions to finish 2025/05/01 06:31:46 INFO : three.txt: Moved (server-side) to: three.txt.bak 2025/05/01 06:31:46 INFO : three.txt: Moved into backup dir 2025/05/01 06:31:48 DEBUG : dst/three.txt: md5 = 66743d2054fd58051cbdbf0a81334bfb OK 2025/05/01 06:31:49 DEBUG : three.txt.bak: Excluded (Path Filter) 2025/05/01 06:31:49 DEBUG : three.txt.bak: Excluded 2025/05/01 06:31:49 DEBUG : one.bak: Excluded (Path Filter) 2025/05/01 06:31:49 DEBUG : one.bak: Excluded 2025/05/01 06:31:49 DEBUG : one: Sizes differ (src 5 vs dst 4) 2025/05/01 06:31:49 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zedurer9kufu/dst': Waiting for checks to finish 2025/05/01 06:31:49 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/05/01 06:31:49 DEBUG : two: Unchanged skipping 2025/05/01 06:31:50 INFO : one.bak: Deleted 2025/05/01 06:31:50 INFO : one: Moved (server-side) to: one.bak 2025/05/01 06:31:50 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zedurer9kufu/dst': Waiting for transfers to finish 2025/05/01 06:31:51 DEBUG : one: md5 = 92e6791eb99e73655921c1d9d9aa5b34 OK 2025/05/01 06:31:51 INFO : one: Copied (new) 2025/05/01 06:31:51 DEBUG : Waiting for deletions to finish 2025/05/01 06:31:52 INFO : three.txt.bak: Deleted 2025/05/01 06:31:53 INFO : three.txt: Moved (server-side) to: three.txt.bak 2025/05/01 06:31:53 INFO : three.txt: Moved into backup dir 2025/05/01 06:31:55 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" 2025/05/01 06:31:55 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "qltcak2uaegtmcoa8vijdppbp8" 2025/05/01 06:31:55 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "sk91qgsqfn0r271r2ehsaoc20c" 2025/05/01 06:31:55 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "sk91qgsqfn0r271r2ehsaoc20c" 2025/05/01 06:31:55 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "qltcak2uaegtmcoa8vijdppbp8" 2025/05/01 06:31:55 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k" --- PASS: TestSyncBackupDirSuffixOnly (18.88s) === RUN TestSyncSuffix run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zedurer9kufu'", Local "Local file system at /tmp/rclone1815725417", Modify Window "1ms" 2025/05/01 06:31:58 DEBUG : dst/one: md5 = 3eada09b5bc9b6c57a3945ed09073ba7 OK 2025/05/01 06:31:59 DEBUG : dst/two: md5 = 978405c733af1c100fc5b102c7ce8c2a OK 2025/05/01 06:32:01 DEBUG : dst/three.txt: md5 = 8e548f97a7f5445d651fb9b345700854 OK 2025/05/01 06:32:01 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-zedurer9kufu/dst" 2025/05/01 06:32:01 DEBUG : Creating backend with remote "TestDrive:crypt/8qbvuohkaa3egsv9bvujjbl2eclmttfbdc6hgn8m0s7jo9antms0/31u3jie661vd5p8j7rtc3hgbh0" 2025/05/01 06:32:02 DEBUG : one: Sizes differ (src 4 vs dst 3) 2025/05/01 06:32:03 INFO : one: Moved (server-side) to: one.bak 2025/05/01 06:32:04 DEBUG : one: md5 = 526d9c4c3c90c115a30c67f6458ef982 OK 2025/05/01 06:32:04 INFO : one: Copied (new) 2025/05/01 06:32:05 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/05/01 06:32:05 DEBUG : two: Unchanged skipping 2025/05/01 06:32:05 DEBUG : three.txt: Sizes differ (src 6 vs dst 5) 2025/05/01 06:32:06 INFO : three.txt: Moved (server-side) to: three.txt.bak 2025/05/01 06:32:07 DEBUG : three.txt: md5 = 2cd9d48e7a998e086a71b0967bf0b8dd OK 2025/05/01 06:32:07 INFO : three.txt: Copied (new) 2025/05/01 06:32:08 DEBUG : one: Sizes differ (src 5 vs dst 4) 2025/05/01 06:32:09 INFO : one.bak: Deleted 2025/05/01 06:32:09 INFO : one: Moved (server-side) to: one.bak 2025/05/01 06:32:10 DEBUG : one: md5 = ea252f0ae3e80d6274942b0fc3825e86 OK 2025/05/01 06:32:10 INFO : one: Copied (new) 2025/05/01 06:32:11 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/05/01 06:32:11 DEBUG : two: Unchanged skipping 2025/05/01 06:32:11 DEBUG : three.txt: Sizes differ (src 19 vs dst 6) 2025/05/01 06:32:12 INFO : three.txt.bak: Deleted 2025/05/01 06:32:12 INFO : three.txt: Moved (server-side) to: three.txt.bak 2025/05/01 06:32:13 DEBUG : three.txt: md5 = 99b4a6f719fa603329ac629729d423c3 OK 2025/05/01 06:32:13 INFO : three.txt: Copied (new) 2025/05/01 06:32:17 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" 2025/05/01 06:32:17 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "tr2hj63d80ftlmvm6a952snjcc" 2025/05/01 06:32:17 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "qltcak2uaegtmcoa8vijdppbp8" 2025/05/01 06:32:17 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "sk91qgsqfn0r271r2ehsaoc20c" 2025/05/01 06:32:17 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "sk91qgsqfn0r271r2ehsaoc20c" 2025/05/01 06:32:17 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k" 2025/05/01 06:32:17 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "qltcak2uaegtmcoa8vijdppbp8" --- PASS: TestSyncSuffix (21.71s) === RUN TestSyncSuffixKeepExtension run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zedurer9kufu'", Local "Local file system at /tmp/rclone1815725417", Modify Window "1ms" 2025/05/01 06:32:20 DEBUG : dst/one: md5 = c442327e440a56937ef655ee0816092b OK 2025/05/01 06:32:21 DEBUG : dst/two: md5 = 2ddfc56510475ae4caf62d095900685a OK 2025/05/01 06:32:22 DEBUG : dst/three.txt: md5 = c1b0d88c08e661238fd67a901a9d41ab OK 2025/05/01 06:32:23 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-zedurer9kufu/dst" 2025/05/01 06:32:23 DEBUG : Creating backend with remote "TestDrive:crypt/8qbvuohkaa3egsv9bvujjbl2eclmttfbdc6hgn8m0s7jo9antms0/31u3jie661vd5p8j7rtc3hgbh0" 2025/05/01 06:32:24 DEBUG : one: Sizes differ (src 4 vs dst 3) 2025/05/01 06:32:25 INFO : one: Moved (server-side) to: one-2019-01-01 2025/05/01 06:32:26 DEBUG : one: md5 = 0dc0313190114f4052e32550dddf9149 OK 2025/05/01 06:32:26 INFO : one: Copied (new) 2025/05/01 06:32:27 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/05/01 06:32:27 DEBUG : two: Unchanged skipping 2025/05/01 06:32:27 DEBUG : three.txt: Sizes differ (src 6 vs dst 5) 2025/05/01 06:32:28 INFO : three.txt: Moved (server-side) to: three-2019-01-01.txt 2025/05/01 06:32:29 DEBUG : three.txt: md5 = 95801b496da22399a7c255c9ee0e8d1d OK 2025/05/01 06:32:29 INFO : three.txt: Copied (new) 2025/05/01 06:32:30 DEBUG : one: Sizes differ (src 5 vs dst 4) 2025/05/01 06:32:31 INFO : one-2019-01-01: Deleted 2025/05/01 06:32:31 INFO : one: Moved (server-side) to: one-2019-01-01 2025/05/01 06:32:33 DEBUG : one: md5 = 2cc29ff2dcbe08ee51a72006fbdf6188 OK 2025/05/01 06:32:33 INFO : one: Copied (new) 2025/05/01 06:32:33 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/05/01 06:32:33 DEBUG : two: Unchanged skipping 2025/05/01 06:32:33 DEBUG : three.txt: Sizes differ (src 19 vs dst 6) 2025/05/01 06:32:34 INFO : three-2019-01-01.txt: Deleted 2025/05/01 06:32:34 INFO : three.txt: Moved (server-side) to: three-2019-01-01.txt 2025/05/01 06:32:36 DEBUG : three.txt: md5 = 0030041dcf7c0a64f1eddcea2401afa7 OK 2025/05/01 06:32:36 INFO : three.txt: Copied (new) 2025/05/01 06:32:39 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "tr2hj63d80ftlmvm6a952snjcc" 2025/05/01 06:32:39 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" 2025/05/01 06:32:39 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "jcjl1bv3ep0v8kt35lqql1co90" 2025/05/01 06:32:39 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "jcjl1bv3ep0v8kt35lqql1co90" 2025/05/01 06:32:39 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "qtq2f6qq4lgpsmj88vb7147qje3prudmtfdtr2342fth58vo9a50" 2025/05/01 06:32:39 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k" 2025/05/01 06:32:39 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "qtq2f6qq4lgpsmj88vb7147qje3prudmtfdtr2342fth58vo9a50" --- PASS: TestSyncSuffixKeepExtension (21.85s) === RUN TestSyncUTFNorm run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zedurer9kufu'", Local "Local file system at /tmp/rclone1815725417", Modify Window "1ms" 2025/05/01 06:32:41 DEBUG : Testêé: md5 = 47311f5e2d3bf6d31130c4b126400d38 OK 2025/05/01 06:32:41 DEBUG : Testêé: Sizes differ (src 14 vs dst 18) 2025/05/01 06:32:41 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zedurer9kufu': Waiting for checks to finish 2025/05/01 06:32:41 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zedurer9kufu': Waiting for transfers to finish 2025/05/01 06:32:42 DEBUG : Testêé: md5 = c7cf0088c245f3dc370e0ed24a10aa81 OK 2025/05/01 06:32:42 INFO : Testêé: Copied (replaced existing) to: Testêé 2025/05/01 06:32:42 DEBUG : Waiting for deletions to finish --- PASS: TestSyncUTFNorm (3.95s) === RUN TestSyncImmutable run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zedurer9kufu'", Local "Local file system at /tmp/rclone1815725417", Modify Window "1ms" 2025/05/01 06:32:44 DEBUG : existing: Need to transfer - File not found at Destination 2025/05/01 06:32:44 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zedurer9kufu': Waiting for checks to finish 2025/05/01 06:32:44 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zedurer9kufu': Waiting for transfers to finish 2025/05/01 06:32:45 DEBUG : existing: md5 = 038162db321f41d7faa7108aa947d9c4 OK 2025/05/01 06:32:45 INFO : existing: Copied (new) 2025/05/01 06:32:45 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zedurer9kufu'", Local "Local file system at /tmp/rclone1815725417", Modify Window "1ms" 2025/05/01 06:32:46 DEBUG : existing: Sizes differ (src 8 vs dst 6) 2025/05/01 06:32:46 ERROR : existing: Source and destination exist but do not match: immutable file modified 2025/05/01 06:32:46 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zedurer9kufu': Waiting for checks to finish 2025/05/01 06:32:46 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zedurer9kufu': Waiting for transfers to finish 2025/05/01 06:32:46 ERROR : Encrypted drive 'TestCryptDrive:rclone-test-zedurer9kufu': not deleting files as there were IO errors 2025/05/01 06:32:46 ERROR : Encrypted drive 'TestCryptDrive:rclone-test-zedurer9kufu': not deleting directories as there were IO errors run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zedurer9kufu'", Local "Local file system at /tmp/rclone1815725417", Modify Window "1ms" --- PASS: TestSyncImmutable (4.56s) === RUN TestSyncIgnoreCase run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zedurer9kufu'", Local "Local file system at /tmp/rclone1815725417", Modify Window "1ms" 2025/05/01 06:32:49 DEBUG : EXISTING: md5 = 6632c3ecaeaf673b2520e28be5da7675 OK 2025/05/01 06:32:50 DEBUG : existing: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/05/01 06:32:50 DEBUG : existing: Unchanged skipping 2025/05/01 06:32:50 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zedurer9kufu': Waiting for checks to finish 2025/05/01 06:32:50 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zedurer9kufu': Waiting for transfers to finish 2025/05/01 06:32:50 DEBUG : Waiting for deletions to finish 2025/05/01 06:32:50 INFO : There was nothing to transfer --- PASS: TestSyncIgnoreCase (3.04s) === RUN TestFixCase run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zedurer9kufu'", Local "Local file system at /tmp/rclone1815725417", Modify Window "1ms" sync_test.go:2635: Skipping test as local or remote are case-sensitive --- SKIP: TestFixCase (0.45s) === RUN TestMaxTransfer === RUN TestMaxTransfer/Hard run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zedurer9kufu'", Local "Local file system at /tmp/rclone1815725417", 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-zedurer9kufu'", Local "Local file system at /tmp/rclone1815725417", 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-zedurer9kufu'", Local "Local file system at /tmp/rclone1815725417", Modify Window "1ms" sync_test.go:2674: This test only runs on local --- PASS: TestMaxTransfer (1.39s) --- SKIP: TestMaxTransfer/Hard (0.51s) --- SKIP: TestMaxTransfer/Soft (0.43s) --- SKIP: TestMaxTransfer/Cautious (0.45s) === RUN TestSyncConcurrentDelete run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zedurer9kufu'", Local "Local file system at /tmp/rclone1815725417", Modify Window "1ms" 2025/05/01 06:32:54 DEBUG : both0: md5 = fea0b8c37b80ce2dd59f4199b237fd30 OK 2025/05/01 06:32:56 DEBUG : only0: md5 = b17e0c25db89fce144f0955c1b63bb1c OK 2025/05/01 06:32:57 DEBUG : both1: md5 = b58fd3c5effdab7eb3ca2d2d670d6a91 OK 2025/05/01 06:32:58 DEBUG : only1: md5 = 6d3f0f9c5a11b78011b4c0e4ac0552c9 OK 2025/05/01 06:33:00 DEBUG : both2: md5 = 0b6ec56c542ecd663dcfde6c45c6a8d3 OK 2025/05/01 06:33:01 DEBUG : only2: md5 = cad204977ec04a20c5af77d86d772f2d OK 2025/05/01 06:33:02 DEBUG : both3: md5 = 31533c26b4cbd645d40dd1e2756809ce OK 2025/05/01 06:33:04 DEBUG : only3: md5 = 03eb420ca8ce6f9d92a1cc7f1e09f37e OK 2025/05/01 06:33:05 DEBUG : both4: md5 = 3ace221faefcab5a4f5ca223e75124ea OK 2025/05/01 06:33:06 DEBUG : only4: md5 = 88ab19767e991f8f82c61e18cf36b0c1 OK 2025/05/01 06:33:08 DEBUG : both5: md5 = 18ba7454f291fdd1b11beddba9a85ba2 OK 2025/05/01 06:33:09 DEBUG : only5: md5 = 4e1833339f00d4baa44f236c3cf84552 OK 2025/05/01 06:33:10 DEBUG : both6: md5 = e7fe00265902109edcb8f1bd53ff8007 OK 2025/05/01 06:33:12 DEBUG : only6: md5 = 409aab8938dadc3cd500c8a8acd1b23d OK 2025/05/01 06:33:13 DEBUG : both7: md5 = 758cbe3e9fbfb797e0bd5595a93614c6 OK 2025/05/01 06:33:14 DEBUG : only7: md5 = 311a6d62a7ee0b0481629fd7cba90999 OK 2025/05/01 06:33:16 DEBUG : both8: md5 = f6dbe0c1c1221259131ed42b3b516e30 OK 2025/05/01 06:33:17 DEBUG : only8: md5 = c77a43f7ba2878188b204fe93112de98 OK 2025/05/01 06:33:19 DEBUG : both9: md5 = be5b286bc2a912e8c167ca4327f80fe3 OK 2025/05/01 06:33:20 DEBUG : only9: md5 = 6205c51c763413d62be84ac9ad2878f3 OK 2025/05/01 06:33:21 DEBUG : both10: md5 = 3a8f592d1dcee6dbe1bb0ed1e0e9cebf OK 2025/05/01 06:33:23 DEBUG : only10: md5 = ccce897f47c46bcd698be091fc9c23cd OK 2025/05/01 06:33:24 DEBUG : both11: md5 = 2bef040bc77e472266f8e4d6fe431530 OK 2025/05/01 06:33:25 DEBUG : only11: md5 = 53ec453c7d4ef56b1f27cbe92e59015c OK 2025/05/01 06:33:27 DEBUG : both12: md5 = 71f5d8046e652f0baf27cb1fbda6eabb OK 2025/05/01 06:33:28 DEBUG : only12: md5 = 0228103b559507aebbd58966773f2e08 OK 2025/05/01 06:33:29 DEBUG : both13: md5 = a8212ad215b6e3fef50acfbdfe2f848e OK 2025/05/01 06:33:31 DEBUG : only13: md5 = 38ae0b799afab96489320ca72447f5df OK 2025/05/01 06:33:32 DEBUG : both14: md5 = 6fb7ff8631f671b950ea2a8981e63800 OK 2025/05/01 06:33:33 DEBUG : only14: md5 = 4a816fe87a81d7ef6cbed059f31f5f64 OK 2025/05/01 06:33:35 DEBUG : both15: md5 = 66c99ad63e861af524afca7615ad75bb OK 2025/05/01 06:33:36 DEBUG : only15: md5 = 6ca6f4169f3cc54598d146cbe0021ae0 OK 2025/05/01 06:33:38 DEBUG : both16: md5 = e6c08d3f84d41057dc851cc630b8b451 OK 2025/05/01 06:33:39 DEBUG : only16: md5 = f9756b50f88df8c3a0bfdc2b13865894 OK 2025/05/01 06:33:41 DEBUG : both17: md5 = 3a278d7a469f9afefd9900ec8a0c59b9 OK 2025/05/01 06:33:42 DEBUG : only17: md5 = 69319c9c7a7d1b6de2921c89f00c4f35 OK 2025/05/01 06:33:43 DEBUG : both18: md5 = 014919a436fe8183342876e8bb4ed39e OK 2025/05/01 06:33:45 DEBUG : only18: md5 = a4b45967867f7783dc8e6fd9469b3f3d OK 2025/05/01 06:33:46 DEBUG : both19: md5 = 497382762a6c730dada15eb5cac21409 OK 2025/05/01 06:33:47 DEBUG : only19: md5 = 1b2076621130e29faee9eab5aafcd7d6 OK 2025/05/01 06:33:48 DEBUG : both0: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/05/01 06:33:48 DEBUG : both0: Unchanged skipping 2025/05/01 06:33:48 DEBUG : both1: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/05/01 06:33:48 DEBUG : both1: Unchanged skipping 2025/05/01 06:33:48 DEBUG : both10: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/05/01 06:33:48 DEBUG : both10: Unchanged skipping 2025/05/01 06:33:48 DEBUG : both11: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/05/01 06:33:48 DEBUG : both11: Unchanged skipping 2025/05/01 06:33:48 DEBUG : both13: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/05/01 06:33:48 DEBUG : both12: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/05/01 06:33:48 DEBUG : both14: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/05/01 06:33:48 DEBUG : both15: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/05/01 06:33:48 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zedurer9kufu': Waiting for checks to finish 2025/05/01 06:33:48 DEBUG : both13: Unchanged skipping 2025/05/01 06:33:48 DEBUG : both16: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/05/01 06:33:48 DEBUG : both16: Unchanged skipping 2025/05/01 06:33:48 DEBUG : both17: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/05/01 06:33:48 DEBUG : both17: Unchanged skipping 2025/05/01 06:33:48 DEBUG : both18: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/05/01 06:33:48 DEBUG : both18: Unchanged skipping 2025/05/01 06:33:48 DEBUG : both19: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/05/01 06:33:48 DEBUG : both19: Unchanged skipping 2025/05/01 06:33:48 DEBUG : both2: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/05/01 06:33:48 DEBUG : both2: Unchanged skipping 2025/05/01 06:33:48 DEBUG : both3: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/05/01 06:33:48 DEBUG : both3: Unchanged skipping 2025/05/01 06:33:48 DEBUG : both4: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/05/01 06:33:48 DEBUG : both4: Unchanged skipping 2025/05/01 06:33:48 DEBUG : both5: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/05/01 06:33:48 DEBUG : both5: Unchanged skipping 2025/05/01 06:33:48 DEBUG : both6: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/05/01 06:33:48 DEBUG : both6: Unchanged skipping 2025/05/01 06:33:48 DEBUG : both7: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/05/01 06:33:48 DEBUG : both7: Unchanged skipping 2025/05/01 06:33:48 DEBUG : both8: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/05/01 06:33:48 DEBUG : both8: Unchanged skipping 2025/05/01 06:33:48 DEBUG : both9: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/05/01 06:33:48 DEBUG : both9: Unchanged skipping 2025/05/01 06:33:48 DEBUG : both12: Unchanged skipping 2025/05/01 06:33:48 DEBUG : both14: Unchanged skipping 2025/05/01 06:33:48 DEBUG : both15: Unchanged skipping 2025/05/01 06:33:48 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zedurer9kufu': Waiting for transfers to finish 2025/05/01 06:33:48 DEBUG : Waiting for deletions to finish 2025/05/01 06:33:48 INFO : only15: Deleted 2025/05/01 06:33:48 INFO : only17: Deleted 2025/05/01 06:33:48 INFO : only4: Deleted 2025/05/01 06:33:48 INFO : only6: Deleted 2025/05/01 06:33:49 INFO : only19: Deleted 2025/05/01 06:33:49 INFO : only13: Deleted 2025/05/01 06:33:49 INFO : only1: Deleted 2025/05/01 06:33:49 INFO : only16: Deleted 2025/05/01 06:33:49 INFO : only9: Deleted 2025/05/01 06:33:49 INFO : only18: Deleted 2025/05/01 06:33:49 INFO : only7: Deleted 2025/05/01 06:33:49 INFO : only0: Deleted 2025/05/01 06:33:50 INFO : only12: Deleted 2025/05/01 06:33:50 INFO : only10: Deleted 2025/05/01 06:33:50 INFO : only2: Deleted 2025/05/01 06:33:50 INFO : only8: Deleted 2025/05/01 06:33:50 INFO : only11: Deleted 2025/05/01 06:33:50 INFO : only14: Deleted 2025/05/01 06:33:50 INFO : only3: Deleted 2025/05/01 06:33:50 INFO : only5: Deleted 2025/05/01 06:33:50 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zedurer9kufu'", Local "Local file system at /tmp/rclone1815725417", Modify Window "1ms" --- PASS: TestSyncConcurrentDelete (67.13s) === RUN TestSyncConcurrentTruncate run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zedurer9kufu'", Local "Local file system at /tmp/rclone1815725417", Modify Window "1ms" 2025/05/01 06:34:01 DEBUG : both0: md5 = 858d2a5908a33101e5e7f50abc8e5e1a OK 2025/05/01 06:34:03 DEBUG : only0: md5 = 2ba001e46e5a1bfdf77f9ac328822db6 OK 2025/05/01 06:34:04 DEBUG : both1: md5 = 1764b3c2016026fd8a86518660ad108a OK 2025/05/01 06:34:06 DEBUG : only1: md5 = dd2c6b11f8b541ccce7fc3414fd7b32d OK 2025/05/01 06:34:07 DEBUG : both2: md5 = c27b0ecf8d30e731071163eaaefb8e96 OK 2025/05/01 06:34:08 DEBUG : only2: md5 = 0e3108c878397dbe75006df7198ae23a OK 2025/05/01 06:34:10 DEBUG : both3: md5 = 15d0a30e0c817163d5f2d680312f5f17 OK 2025/05/01 06:34:11 DEBUG : only3: md5 = d395aa13598fd942d5eacadfbbd09b77 OK 2025/05/01 06:34:12 DEBUG : both4: md5 = 304b6245f1f09de76e8bad130e5396f7 OK 2025/05/01 06:34:14 DEBUG : only4: md5 = d65302321b61e4d17f4838c871991b52 OK 2025/05/01 06:34:15 DEBUG : both5: md5 = 1228509432d6f05d7468f8f9b4148ecc OK 2025/05/01 06:34:16 DEBUG : only5: md5 = 9c3893554c245077caf94f4d2f1d6807 OK 2025/05/01 06:34:18 DEBUG : both6: md5 = 6e6ad17b80c7c5ef8749183c0b4b4a5d OK 2025/05/01 06:34:19 DEBUG : only6: md5 = 91b9785c66ddaca8c6222ce0b85eb1d6 OK 2025/05/01 06:34:20 DEBUG : both7: md5 = bdc94dc04c6c36265c6407597dd88c75 OK 2025/05/01 06:34:21 DEBUG : only7: md5 = 1e382273cf5b0b88a2f1d7b7d01fb7ee OK 2025/05/01 06:34:23 DEBUG : both8: md5 = 3632eb9d137aadfcad7cf384076db683 OK 2025/05/01 06:34:24 DEBUG : only8: md5 = fe936e831217bdc39c7fba71e1531f75 OK 2025/05/01 06:34:25 DEBUG : both9: md5 = 1335e4991dafeff0bfc374e6ac354b54 OK 2025/05/01 06:34:27 DEBUG : only9: md5 = 966ecb5e03f832f93ec76f2069b1030e OK 2025/05/01 06:34:28 DEBUG : both10: md5 = eee9d25f7fdd0625fda3e02a9b32e116 OK 2025/05/01 06:34:29 DEBUG : only10: md5 = 98241164aa0c4c5f2179d8a187e063bf OK 2025/05/01 06:34:31 DEBUG : both11: md5 = 98636c8810be3571f5546c9e35f47757 OK 2025/05/01 06:34:32 DEBUG : only11: md5 = 1e344a9670a877d462da59c726310e59 OK 2025/05/01 06:34:33 DEBUG : both12: md5 = 714f162af92e706d0f96d73475c0519c OK 2025/05/01 06:34:34 DEBUG : only12: md5 = 0dc73d0c2379a4bf2a23f9fb2009f0f6 OK 2025/05/01 06:34:36 DEBUG : both13: md5 = 1af52452fa8b1b512058de7023e22021 OK 2025/05/01 06:34:37 DEBUG : only13: md5 = 222109096bd32cdad9b66b060f5a2a97 OK 2025/05/01 06:34:38 DEBUG : both14: md5 = 73f98ab836f148fa6ad5f98d89b30400 OK 2025/05/01 06:34:40 DEBUG : only14: md5 = a26962077b3159a51f954ad40d1bd3ee OK 2025/05/01 06:34:41 DEBUG : both15: md5 = 94492c54ee975153d05ce0ffef5cdaaf OK 2025/05/01 06:34:42 DEBUG : only15: md5 = 2ef195df2c902d67a1222e0416da81bb OK 2025/05/01 06:34:44 DEBUG : both16: md5 = a2652d93fd73918a3ce2e67288d322b1 OK 2025/05/01 06:34:45 DEBUG : only16: md5 = 6f246c317e439bb66d1c081bc3d02994 OK 2025/05/01 06:34:46 DEBUG : both17: md5 = 9254a1fbf2ae29d5d7385741117e7e62 OK 2025/05/01 06:34:48 DEBUG : only17: md5 = fc244b3cb3f5ed7adae4b0b8f2276de9 OK 2025/05/01 06:34:49 DEBUG : both18: md5 = 5e34cb49d9576341a25d409f4200f16c OK 2025/05/01 06:34:50 DEBUG : only18: md5 = a87e1a05bf0c24613bf823a4e6505d12 OK 2025/05/01 06:34:52 DEBUG : both19: md5 = c7170e826668ff87ef8f2cd33f2ed184 OK 2025/05/01 06:34:53 DEBUG : only19: md5 = 0f9c14090e6b9018337ff01e31919cc3 OK 2025/05/01 06:34:54 DEBUG : both0: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/05/01 06:34:54 DEBUG : both1: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/05/01 06:34:54 DEBUG : both10: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/05/01 06:34:54 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zedurer9kufu': Waiting for checks to finish 2025/05/01 06:34:54 DEBUG : both11: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/05/01 06:34:54 DEBUG : both0: Unchanged skipping 2025/05/01 06:34:54 DEBUG : both12: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/05/01 06:34:54 DEBUG : both1: Unchanged skipping 2025/05/01 06:34:54 DEBUG : both13: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/05/01 06:34:54 DEBUG : both13: Unchanged skipping 2025/05/01 06:34:54 DEBUG : both14: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/05/01 06:34:54 DEBUG : both14: Unchanged skipping 2025/05/01 06:34:54 DEBUG : both15: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/05/01 06:34:54 DEBUG : both15: Unchanged skipping 2025/05/01 06:34:54 DEBUG : both16: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/05/01 06:34:54 DEBUG : both16: Unchanged skipping 2025/05/01 06:34:54 DEBUG : both17: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/05/01 06:34:54 DEBUG : both17: Unchanged skipping 2025/05/01 06:34:54 DEBUG : both18: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/05/01 06:34:54 DEBUG : both18: Unchanged skipping 2025/05/01 06:34:54 DEBUG : both19: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/05/01 06:34:54 DEBUG : both19: Unchanged skipping 2025/05/01 06:34:54 DEBUG : both2: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/05/01 06:34:54 DEBUG : both2: Unchanged skipping 2025/05/01 06:34:54 DEBUG : both3: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/05/01 06:34:54 DEBUG : both3: Unchanged skipping 2025/05/01 06:34:54 DEBUG : both4: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/05/01 06:34:54 DEBUG : both4: Unchanged skipping 2025/05/01 06:34:54 DEBUG : both5: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/05/01 06:34:54 DEBUG : both5: Unchanged skipping 2025/05/01 06:34:54 DEBUG : both6: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/05/01 06:34:54 DEBUG : both6: Unchanged skipping 2025/05/01 06:34:54 DEBUG : both7: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/05/01 06:34:54 DEBUG : both7: Unchanged skipping 2025/05/01 06:34:54 DEBUG : both8: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/05/01 06:34:54 DEBUG : both8: Unchanged skipping 2025/05/01 06:34:54 DEBUG : both9: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/05/01 06:34:54 DEBUG : both9: Unchanged skipping 2025/05/01 06:34:54 DEBUG : only0: Sizes differ (src 0 vs dst 6) 2025/05/01 06:34:54 DEBUG : only1: Sizes differ (src 0 vs dst 6) 2025/05/01 06:34:54 DEBUG : only10: Sizes differ (src 0 vs dst 6) 2025/05/01 06:34:54 DEBUG : only11: Sizes differ (src 0 vs dst 6) 2025/05/01 06:34:54 DEBUG : only12: Sizes differ (src 0 vs dst 6) 2025/05/01 06:34:54 DEBUG : only13: Sizes differ (src 0 vs dst 6) 2025/05/01 06:34:54 DEBUG : only14: Sizes differ (src 0 vs dst 6) 2025/05/01 06:34:54 DEBUG : only15: Sizes differ (src 0 vs dst 6) 2025/05/01 06:34:54 DEBUG : only16: Sizes differ (src 0 vs dst 6) 2025/05/01 06:34:54 DEBUG : only17: Sizes differ (src 0 vs dst 6) 2025/05/01 06:34:54 DEBUG : only18: Sizes differ (src 0 vs dst 6) 2025/05/01 06:34:54 DEBUG : only19: Sizes differ (src 0 vs dst 6) 2025/05/01 06:34:54 DEBUG : both10: Unchanged skipping 2025/05/01 06:34:54 DEBUG : only2: Sizes differ (src 0 vs dst 6) 2025/05/01 06:34:54 DEBUG : only3: Sizes differ (src 0 vs dst 6) 2025/05/01 06:34:54 DEBUG : only4: Sizes differ (src 0 vs dst 6) 2025/05/01 06:34:54 DEBUG : only5: Sizes differ (src 0 vs dst 6) 2025/05/01 06:34:54 DEBUG : only6: Sizes differ (src 0 vs dst 6) 2025/05/01 06:34:54 DEBUG : both11: Unchanged skipping 2025/05/01 06:34:54 DEBUG : only7: Sizes differ (src 0 vs dst 6) 2025/05/01 06:34:54 DEBUG : only8: Sizes differ (src 0 vs dst 6) 2025/05/01 06:34:54 DEBUG : only9: Sizes differ (src 0 vs dst 6) 2025/05/01 06:34:54 DEBUG : both12: Unchanged skipping 2025/05/01 06:34:54 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zedurer9kufu': Waiting for transfers to finish 2025/05/01 06:34:55 DEBUG : only11: md5 = 098e6088d5dbba36554dc7ecf0e5f1fb OK 2025/05/01 06:34:55 INFO : only11: Copied (replaced existing) 2025/05/01 06:34:55 DEBUG : only0: md5 = fdc54954633a8913d11aee1e900cb2a0 OK 2025/05/01 06:34:55 INFO : only0: Copied (replaced existing) 2025/05/01 06:34:55 DEBUG : only10: md5 = 6896d298293a7922cda359c64add35ae OK 2025/05/01 06:34:55 INFO : only10: Copied (replaced existing) 2025/05/01 06:34:55 DEBUG : only1: md5 = 67e0d61c0b7edf45200db0b5e42f953e OK 2025/05/01 06:34:55 INFO : only1: Copied (replaced existing) 2025/05/01 06:34:56 DEBUG : only13: md5 = 0d652c469662f7652723c98dcda98b1a OK 2025/05/01 06:34:56 INFO : only13: Copied (replaced existing) 2025/05/01 06:34:56 DEBUG : only14: md5 = c2d04b7a54fc3f2afc45c9b20f8797d3 OK 2025/05/01 06:34:56 INFO : only14: Copied (replaced existing) 2025/05/01 06:34:56 DEBUG : only12: md5 = 5655d12be2b47551ffcf362d1a0afe0e OK 2025/05/01 06:34:56 INFO : only12: Copied (replaced existing) 2025/05/01 06:34:56 DEBUG : only15: md5 = 00f24dc1baa9d31e608fb6a37a438356 OK 2025/05/01 06:34:56 INFO : only15: Copied (replaced existing) 2025/05/01 06:34:57 DEBUG : only2: md5 = 715a6bb7e5bf6cfe80824668fe1670a3 OK 2025/05/01 06:34:57 INFO : only2: Copied (replaced existing) 2025/05/01 06:34:57 DEBUG : only18: md5 = 5403c44b8d50752b766bd5fbc220f452 OK 2025/05/01 06:34:57 INFO : only18: Copied (replaced existing) 2025/05/01 06:34:57 DEBUG : only17: md5 = a86ab724b75f50835f6d8e283ba88358 OK 2025/05/01 06:34:57 INFO : only17: Copied (replaced existing) 2025/05/01 06:34:57 DEBUG : only16: md5 = 77453a6a96940c81323dc0863ab21224 OK 2025/05/01 06:34:57 INFO : only16: Copied (replaced existing) 2025/05/01 06:34:58 DEBUG : only5: md5 = 566b7783865c7ae477a0c092e3358cf4 OK 2025/05/01 06:34:58 INFO : only5: Copied (replaced existing) 2025/05/01 06:34:58 DEBUG : only3: md5 = a3ac8bf191333c1fe45c0e0b22f814c9 OK 2025/05/01 06:34:58 INFO : only3: Copied (replaced existing) 2025/05/01 06:34:58 DEBUG : only4: md5 = 5095f399c99917aee96759deb2c6aa4d OK 2025/05/01 06:34:58 INFO : only4: Copied (replaced existing) 2025/05/01 06:34:58 DEBUG : only7: md5 = 05d461feb413d13f79450c35234feeec OK 2025/05/01 06:34:58 INFO : only7: Copied (replaced existing) 2025/05/01 06:34:59 DEBUG : only19: md5 = 4b544b988fd94acc441732ccb7bd5ca7 OK 2025/05/01 06:34:59 INFO : only19: Copied (replaced existing) 2025/05/01 06:34:59 DEBUG : only9: md5 = 6f697bc4f5a476db52017f35e833cb6e OK 2025/05/01 06:34:59 INFO : only9: Copied (replaced existing) 2025/05/01 06:34:59 DEBUG : only6: md5 = e7ead8f019489178a277605ed4b8d83f OK 2025/05/01 06:34:59 INFO : only6: Copied (replaced existing) 2025/05/01 06:34:59 DEBUG : only8: md5 = 6dcc0c14d6deb59fcc4668a6c4168c81 OK 2025/05/01 06:34:59 INFO : only8: Copied (replaced existing) 2025/05/01 06:34:59 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zedurer9kufu'", Local "Local file system at /tmp/rclone1815725417", Modify Window "1ms" --- PASS: TestSyncConcurrentTruncate (78.05s) === RUN TestSyncReplaceDirModTime run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zedurer9kufu'", Local "Local file system at /tmp/rclone1815725417", Modify Window "1ms" 2025/05/01 06:35:18 DEBUG : empty_dir: Making directory with metadata 2025/05/01 06:35:18 INFO : empty_dir: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2025/05/01 06:35:18 DEBUG : empty_on_remote: Making directory with metadata 2025/05/01 06:35:18 INFO : empty_on_remote: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2025/05/01 06:35:18 DEBUG : empty_on_remote: Making directory with metadata 2025/05/01 06:35:19 INFO : empty_on_remote: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zedurer9kufu'", Local "Local file system at /tmp/rclone1815725417", Modify Window "1ms" 2025/05/01 06:35:24 INFO : test_dir1: Set directory modification time (using DirSetModTime) 2025/05/01 06:35:24 INFO : test_dir2: Set directory modification time (using DirSetModTime) 2025/05/01 06:35:24 INFO : test_dir2/sub_dir: Set directory modification time (using DirSetModTime) 2025/05/01 06:35:24 INFO : empty_on_remote: Set directory modification time (using DirSetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zedurer9kufu'", Local "Local file system at /tmp/rclone1815725417", Modify Window "1ms" 2025/05/01 06:35:30 DEBUG : heqj02jg0dcqlem7gl0500bvp0/24g2k8bseitblkmqnie1ibl2s8: Rmdir: contains trashed file: "633fmaa0qic3kv3cladnu11pto" 2025/05/01 06:35:31 DEBUG : heqj02jg0dcqlem7gl0500bvp0: Rmdir: contains trashed file: "24g2k8bseitblkmqnie1ibl2s8" 2025/05/01 06:35:32 DEBUG : gq68srrpl0nnf394bgf7dbu9kc: Rmdir: contains trashed file: "d26uovf0miqhd1mu3c9jbseq00" --- PASS: TestSyncReplaceDirModTime (15.52s) === RUN TestSyncReplaceDirModTimeWithEmptyDirs run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zedurer9kufu'", Local "Local file system at /tmp/rclone1815725417", Modify Window "1ms" 2025/05/01 06:35:34 DEBUG : empty_dir: Making directory with metadata 2025/05/01 06:35:34 INFO : empty_dir: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2025/05/01 06:35:34 DEBUG : empty_on_remote: Making directory with metadata 2025/05/01 06:35:34 INFO : empty_on_remote: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2025/05/01 06:35:34 DEBUG : empty_on_remote: Making directory with metadata 2025/05/01 06:35:35 INFO : empty_on_remote: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zedurer9kufu'", Local "Local file system at /tmp/rclone1815725417", Modify Window "1ms" 2025/05/01 06:35:39 INFO : test_dir1: Set directory modification time (using DirSetModTime) 2025/05/01 06:35:39 INFO : test_dir2: Set directory modification time (using DirSetModTime) 2025/05/01 06:35:39 INFO : test_dir2/sub_dir: Set directory modification time (using DirSetModTime) 2025/05/01 06:35:39 INFO : empty_on_remote: Set directory modification time (using DirSetModTime) 2025/05/01 06:35:39 INFO : empty_dir: Set directory modification time (using DirSetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zedurer9kufu'", Local "Local file system at /tmp/rclone1815725417", Modify Window "1ms" 2025/05/01 06:35:46 DEBUG : heqj02jg0dcqlem7gl0500bvp0/24g2k8bseitblkmqnie1ibl2s8: Rmdir: contains trashed file: "633fmaa0qic3kv3cladnu11pto" 2025/05/01 06:35:47 DEBUG : heqj02jg0dcqlem7gl0500bvp0: Rmdir: contains trashed file: "24g2k8bseitblkmqnie1ibl2s8" 2025/05/01 06:35:48 DEBUG : gq68srrpl0nnf394bgf7dbu9kc: Rmdir: contains trashed file: "d26uovf0miqhd1mu3c9jbseq00" --- PASS: TestSyncReplaceDirModTimeWithEmptyDirs (17.07s) === RUN TestNothingToTransferWithEmptyDirs run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zedurer9kufu'", Local "Local file system at /tmp/rclone1815725417", Modify Window "1ms" 2025/05/01 06:35:51 INFO : sub dir: Set directory modification time (using DirSetModTime) 2025/05/01 06:35:51 DEBUG : sub dir: Making directory with metadata 2025/05/01 06:35:52 INFO : sub dir: Made directory with metadata (mtime=2011-12-30T12:59:59Z) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zedurer9kufu'", Local "Local file system at /tmp/rclone1815725417", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zedurer9kufu'", Local "Local file system at /tmp/rclone1815725417", Modify Window "1ms" 2025/05/01 06:36:08 INFO : sub dir2: Set directory modification time (using DirSetModTime) 2025/05/01 06:36:09 INFO : sub dir2: Set directory modification time (using DirSetModTime) 2025/05/01 06:36:09 INFO : sub dirEmpty/sub dirEmpty2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2025/05/01 06:36:09 INFO : sub dirEmpty: Set directory modification time (using DirSetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zedurer9kufu'", Local "Local file system at /tmp/rclone1815725417", Modify Window "1ms" 2025/05/01 06:36:21 DEBUG : gcsdkq814sbtppue42dpsbg8ug: Rmdir: contains trashed file: "sjuo65gk5q3r1199jselk9k9o0" 2025/05/01 06:36:22 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/37qp6d1gohacv723ij3brofbu8/i24n0ln37pa2hv8pctddeuh73o: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" 2025/05/01 06:36:23 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/37qp6d1gohacv723ij3brofbu8: Rmdir: contains trashed file: "i24n0ln37pa2hv8pctddeuh73o" 2025/05/01 06:36:23 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "37qp6d1gohacv723ij3brofbu8" 2025/05/01 06:36:24 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak" 2025/05/01 06:36:25 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak" 2025/05/01 06:36:25 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak" 2025/05/01 06:36:26 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak" 2025/05/01 06:36:27 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/4r13oncfa2rsrr82oqhsqv24ns: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" 2025/05/01 06:36:27 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc: Rmdir: contains trashed file: "4r13oncfa2rsrr82oqhsqv24ns" 2025/05/01 06:36:27 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak" 2025/05/01 06:36:28 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestNothingToTransferWithEmptyDirs (39.36s) === RUN TestNothingToTransferWithoutEmptyDirs run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zedurer9kufu'", Local "Local file system at /tmp/rclone1815725417", Modify Window "1ms" 2025/05/01 06:36:30 INFO : sub dir: Set directory modification time (using DirSetModTime) 2025/05/01 06:36:30 DEBUG : sub dir: Making directory with metadata 2025/05/01 06:36:31 INFO : sub dir: Made directory with metadata (mtime=2011-12-30T12:59:59Z) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zedurer9kufu'", Local "Local file system at /tmp/rclone1815725417", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zedurer9kufu'", Local "Local file system at /tmp/rclone1815725417", Modify Window "1ms" 2025/05/01 06:36:51 INFO : sub dir2: Set directory modification time (using DirSetModTime) 2025/05/01 06:36:52 INFO : sub dir2: Set directory modification time (using DirSetModTime) 2025/05/01 06:36:52 INFO : sub dirEmpty/sub dirEmpty2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2025/05/01 06:36:52 INFO : sub dirEmpty: Set directory modification time (using DirSetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zedurer9kufu'", Local "Local file system at /tmp/rclone1815725417", Modify Window "1ms" 2025/05/01 06:37:02 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/37qp6d1gohacv723ij3brofbu8/i24n0ln37pa2hv8pctddeuh73o: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" 2025/05/01 06:37:03 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/37qp6d1gohacv723ij3brofbu8: Rmdir: contains trashed file: "i24n0ln37pa2hv8pctddeuh73o" 2025/05/01 06:37:04 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "37qp6d1gohacv723ij3brofbu8" 2025/05/01 06:37:04 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak" 2025/05/01 06:37:05 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak" 2025/05/01 06:37:06 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak" 2025/05/01 06:37:06 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak" 2025/05/01 06:37:07 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/4r13oncfa2rsrr82oqhsqv24ns: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" 2025/05/01 06:37:08 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc: Rmdir: contains trashed file: "4r13oncfa2rsrr82oqhsqv24ns" 2025/05/01 06:37:08 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak" 2025/05/01 06:37:08 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestNothingToTransferWithoutEmptyDirs (40.03s) PASS 2025/05/01 06:37:10 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zedurer9kufu': Purge remote "./sync.test -test.v -test.timeout 1h0m0s -remote TestCryptDrive: -verbose" - Finished OK in 16m30.844307128s (try 1/5)