"./sync.test -test.v -test.timeout 1h0m0s -remote TestCryptDrive: -verbose" - Starting (try 1/5) 2025/03/13 01:21:54 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-vawaqoj2yalo" 2025/03/13 01:21:54 DEBUG : Using config file from "/home/rclone/.rclone.conf" 2025/03/13 01:21:54 DEBUG : Creating backend with remote "TestDrive:crypt/bi93ndoe3d0009gfdvhp48majuk0hb7ragk7jqa0ephthkp8fgq0" 2025/03/13 01:21:57 DEBUG : Creating backend with remote "/tmp/rclone342727432" === RUN TestPipe --- PASS: TestPipe (0.00s) === RUN TestPipeConcurrent --- PASS: TestPipeConcurrent (0.03s) === RUN TestPipeOrderBy === RUN TestPipeOrderBy/#00 === RUN TestPipeOrderBy/size === RUN TestPipeOrderBy/name === RUN TestPipeOrderBy/modtime === RUN TestPipeOrderBy/size,ascending === RUN TestPipeOrderBy/name,asc === RUN TestPipeOrderBy/modtime,ascending === RUN TestPipeOrderBy/size,descending === RUN TestPipeOrderBy/name,desc === RUN TestPipeOrderBy/modtime,descending === RUN TestPipeOrderBy/size,mixed,50 === RUN TestPipeOrderBy/size,mixed,51 --- PASS: TestPipeOrderBy (0.00s) --- PASS: TestPipeOrderBy/#00 (0.00s) --- PASS: TestPipeOrderBy/size (0.00s) --- PASS: TestPipeOrderBy/name (0.00s) --- PASS: TestPipeOrderBy/modtime (0.00s) --- PASS: TestPipeOrderBy/size,ascending (0.00s) --- PASS: TestPipeOrderBy/name,asc (0.00s) --- PASS: TestPipeOrderBy/modtime,ascending (0.00s) --- PASS: TestPipeOrderBy/size,descending (0.00s) --- PASS: TestPipeOrderBy/name,desc (0.00s) --- PASS: TestPipeOrderBy/modtime,descending (0.00s) --- PASS: TestPipeOrderBy/size,mixed,50 (0.00s) --- PASS: TestPipeOrderBy/size,mixed,51 (0.00s) === RUN TestNewLess === RUN TestNewLess/blankOK === RUN TestNewLess/tooManyParts === RUN TestNewLess/tooManyParts2 === RUN TestNewLess/badMixed === RUN TestNewLess/unknownComparison === RUN TestNewLess/unknownSortDirection === RUN TestNewLess/size === RUN TestNewLess/name === RUN TestNewLess/modtime === RUN TestNewLess/size,ascending === RUN TestNewLess/name,asc === RUN TestNewLess/modtime,ascending === RUN TestNewLess/size,descending === RUN TestNewLess/name,desc === RUN TestNewLess/modtime,descending === RUN TestNewLess/modtime,mixed === RUN TestNewLess/modtime,mixed,30 --- PASS: TestNewLess (0.00s) --- PASS: TestNewLess/blankOK (0.00s) --- PASS: TestNewLess/tooManyParts (0.00s) --- PASS: TestNewLess/tooManyParts2 (0.00s) --- PASS: TestNewLess/badMixed (0.00s) --- PASS: TestNewLess/unknownComparison (0.00s) --- PASS: TestNewLess/unknownSortDirection (0.00s) --- PASS: TestNewLess/size (0.00s) --- PASS: TestNewLess/name (0.00s) --- PASS: TestNewLess/modtime (0.00s) --- PASS: TestNewLess/size,ascending (0.00s) --- PASS: TestNewLess/name,asc (0.00s) --- PASS: TestNewLess/modtime,ascending (0.00s) --- PASS: TestNewLess/size,descending (0.00s) --- PASS: TestNewLess/name,desc (0.00s) --- PASS: TestNewLess/modtime,descending (0.00s) --- PASS: TestNewLess/modtime,mixed (0.00s) --- PASS: TestNewLess/modtime,mixed,30 (0.00s) === RUN TestRcCopy rc_test.go:16: Skipping test on non local remote --- SKIP: TestRcCopy (0.00s) === RUN TestRcMove rc_test.go:16: Skipping test on non local remote --- SKIP: TestRcMove (0.00s) === RUN TestRcSync rc_test.go:16: Skipping test on non local remote --- SKIP: TestRcSync (0.00s) === RUN TestCopyWithDryRun run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-vawaqoj2yalo'", Local "Local file system at /tmp/rclone342727432", Modify Window "1ms" 2025/03/13 01:21:58 DEBUG : Added delayed dir = "sub dir", newDst= 2025/03/13 01:21:58 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2025/03/13 01:21:58 NOTICE: sub dir/hello world: Skipped copy as --dry-run is set (size 11) 2025/03/13 01:21:58 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vawaqoj2yalo': Waiting for checks to finish 2025/03/13 01:21:58 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vawaqoj2yalo': Waiting for transfers to finish 2025/03/13 01:21:58 NOTICE: sub dir: Skipped set directory modification time as --dry-run is set run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-vawaqoj2yalo'", Local "Local file system at /tmp/rclone342727432", Modify Window "1ms" --- PASS: TestCopyWithDryRun (2.54s) === RUN TestCopy run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-vawaqoj2yalo'", Local "Local file system at /tmp/rclone342727432", Modify Window "1ms" 2025/03/13 01:21:59 INFO : sub dir: Set directory modification time (using DirSetModTime) 2025/03/13 01:21:59 DEBUG : Added delayed dir = "sub dir", newDst= 2025/03/13 01:21:59 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2025/03/13 01:21:59 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vawaqoj2yalo': Waiting for checks to finish 2025/03/13 01:21:59 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vawaqoj2yalo': Waiting for transfers to finish 2025/03/13 01:22:01 DEBUG : sub dir/hello world: md5 = 83efa4f933c6e0b4a81d33a823c13a87 OK 2025/03/13 01:22:01 INFO : sub dir/hello world: Copied (new) 2025/03/13 01:22:04 INFO : sub dir: Set directory modification time (using DirSetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-vawaqoj2yalo'", Local "Local file system at /tmp/rclone342727432", Modify Window "1ms" 2025/03/13 01:22:06 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestCopy (7.66s) === RUN TestCopyMetadata run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-vawaqoj2yalo'", Local "Local file system at /tmp/rclone342727432", Modify Window "1ms" 2025/03/13 01:22:07 DEBUG : metadata sub dir: Making directory with metadata 2025/03/13 01:22:07 INFO : metadata sub dir: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2025/03/13 01:22:07 DEBUG : empty metadata sub dir: Making directory with metadata 2025/03/13 01:22:07 INFO : empty metadata sub dir: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2025/03/13 01:22:07 DEBUG : Local file system at /tmp/rclone342727432: File to upload is small (21 bytes), uploading instead of streaming 2025/03/13 01:22:07 DEBUG : metadata sub dir/hello metadata world: md5 = baa7a013449dbba2b1ed02b5cfb4e1a2 OK 2025/03/13 01:22:07 DEBUG : metadata sub dir/hello metadata world: Size and md5 of src and dst objects identical 2025/03/13 01:22:07 INFO : metadata sub dir: Set directory modification time (using DirSetModTime) 2025/03/13 01:22:07 DEBUG : Google drive root 'crypt/bi93ndoe3d0009gfdvhp48majuk0hb7ragk7jqa0ephthkp8fgq0': Skipping btime metadata as can't update it on an existing file: 2025-03-13T01:22:07.258840983Z 2025/03/13 01:22:11 INFO : empty metadata sub dir: Updated directory metadata 2025/03/13 01:22:11 DEBUG : Google drive root 'crypt/bi93ndoe3d0009gfdvhp48majuk0hb7ragk7jqa0ephthkp8fgq0': Skipping btime metadata as can't update it on an existing file: 2025-03-13T01:22:07.258840983Z 2025/03/13 01:22:12 INFO : metadata sub dir: Updated directory metadata 2025/03/13 01:22:12 DEBUG : metadata sub dir/hello metadata world: Need to transfer - File not found at Destination 2025/03/13 01:22:12 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vawaqoj2yalo': Waiting for checks to finish 2025/03/13 01:22:12 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vawaqoj2yalo': Waiting for transfers to finish 2025/03/13 01:22:13 DEBUG : metadata sub dir/hello metadata world: md5 = f65bc5021d4b6e49df7741f550de561b OK 2025/03/13 01:22:13 INFO : metadata sub dir/hello metadata world: Copied (new) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-vawaqoj2yalo'", Local "Local file system at /tmp/rclone342727432", Modify Window "1ms" 2025/03/13 01:22:20 DEBUG : fg45q1rm3kh00nmmkk4m6ihmrcnel1p7551kqhjr9bk2gtd2gbf0: Rmdir: contains trashed file: "dmuvulfij81f693ur0f1vvbvq9v6iscp56daas3m51n9li5e3470" --- PASS: TestCopyMetadata (15.94s) === RUN TestCopyMetadataNoEmptyDirs run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-vawaqoj2yalo'", Local "Local file system at /tmp/rclone342727432", Modify Window "1ms" 2025/03/13 01:22:23 DEBUG : metadata sub dir: Making directory with metadata 2025/03/13 01:22:23 INFO : metadata sub dir: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2025/03/13 01:22:23 DEBUG : empty metadata sub dir: Making directory with metadata 2025/03/13 01:22:23 INFO : empty metadata sub dir: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2025/03/13 01:22:23 DEBUG : Local file system at /tmp/rclone342727432: File to upload is small (21 bytes), uploading instead of streaming 2025/03/13 01:22:23 DEBUG : metadata sub dir/hello metadata world: md5 = baa7a013449dbba2b1ed02b5cfb4e1a2 OK 2025/03/13 01:22:23 DEBUG : metadata sub dir/hello metadata world: Size and md5 of src and dst objects identical 2025/03/13 01:22:23 INFO : metadata sub dir: Set directory modification time (using DirSetModTime) 2025/03/13 01:22:23 DEBUG : Added delayed dir = "empty metadata sub dir", newDst= 2025/03/13 01:22:23 DEBUG : Added delayed dir = "metadata sub dir", newDst= 2025/03/13 01:22:23 DEBUG : metadata sub dir/hello metadata world: Need to transfer - File not found at Destination 2025/03/13 01:22:23 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vawaqoj2yalo': Waiting for checks to finish 2025/03/13 01:22:23 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vawaqoj2yalo': Waiting for transfers to finish 2025/03/13 01:22:25 DEBUG : metadata sub dir/hello metadata world: md5 = 20dc48eaa97b6c555e3fd699e1973002 OK 2025/03/13 01:22:25 INFO : metadata sub dir/hello metadata world: Copied (new) 2025/03/13 01:22:25 DEBUG : Google drive root 'crypt/bi93ndoe3d0009gfdvhp48majuk0hb7ragk7jqa0ephthkp8fgq0': Skipping btime metadata as can't update it on an existing file: 2025-03-13T01:22:23.198728523Z 2025/03/13 01:22:26 INFO : metadata sub dir: Updated directory metadata run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-vawaqoj2yalo'", Local "Local file system at /tmp/rclone342727432", Modify Window "1ms" 2025/03/13 01:22:29 DEBUG : fg45q1rm3kh00nmmkk4m6ihmrcnel1p7551kqhjr9bk2gtd2gbf0: Rmdir: contains trashed file: "dmuvulfij81f693ur0f1vvbvq9v6iscp56daas3m51n9li5e3470" --- PASS: TestCopyMetadataNoEmptyDirs (7.14s) === RUN TestCopyMissingDirectory run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-vawaqoj2yalo'", Local "Local file system at /tmp/rclone342727432", Modify Window "1ms" 2025/03/13 01:22:30 DEBUG : Creating backend with remote "/non-existing" 2025/03/13 01:22:30 ERROR : Local file system at /non-existing: error reading source root directory: directory not found 2025/03/13 01:22:30 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vawaqoj2yalo': Waiting for checks to finish 2025/03/13 01:22:30 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vawaqoj2yalo': Waiting for transfers to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-vawaqoj2yalo'", Local "Local file system at /tmp/rclone342727432", Modify Window "1ms" --- PASS: TestCopyMissingDirectory (1.22s) === RUN TestCopyNoTraverse run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-vawaqoj2yalo'", Local "Local file system at /tmp/rclone342727432", Modify Window "1ms" 2025/03/13 01:22:31 DEBUG : Added delayed dir = "sub dir", newDst= 2025/03/13 01:22:31 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2025/03/13 01:22:31 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vawaqoj2yalo': Waiting for checks to finish 2025/03/13 01:22:31 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vawaqoj2yalo': Waiting for transfers to finish 2025/03/13 01:22:34 DEBUG : sub dir/hello world: md5 = 89db1a42f67dcff14c22bb96727c477a OK 2025/03/13 01:22:34 INFO : sub dir/hello world: Copied (new) 2025/03/13 01:22:34 INFO : sub dir: Set directory modification time (using DirSetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-vawaqoj2yalo'", Local "Local file system at /tmp/rclone342727432", Modify Window "1ms" 2025/03/13 01:22:36 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestCopyNoTraverse (5.92s) === RUN TestCopyCheckFirst run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-vawaqoj2yalo'", Local "Local file system at /tmp/rclone342727432", Modify Window "1ms" 2025/03/13 01:22:37 INFO : Encrypted drive 'TestCryptDrive:rclone-test-vawaqoj2yalo': Running all checks before starting transfers 2025/03/13 01:22:37 DEBUG : Added delayed dir = "sub dir", newDst= 2025/03/13 01:22:37 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2025/03/13 01:22:37 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vawaqoj2yalo': Waiting for checks to finish 2025/03/13 01:22:37 INFO : Encrypted drive 'TestCryptDrive:rclone-test-vawaqoj2yalo': Checks finished, now starting transfers 2025/03/13 01:22:37 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vawaqoj2yalo': Waiting for transfers to finish 2025/03/13 01:22:40 DEBUG : sub dir/hello world: md5 = 0c501631e86e6d348728f695022cd301 OK 2025/03/13 01:22:40 INFO : sub dir/hello world: Copied (new) 2025/03/13 01:22:40 INFO : sub dir: Set directory modification time (using DirSetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-vawaqoj2yalo'", Local "Local file system at /tmp/rclone342727432", Modify Window "1ms" 2025/03/13 01:22:42 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestCopyCheckFirst (5.99s) === RUN TestSyncNoTraverse run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-vawaqoj2yalo'", Local "Local file system at /tmp/rclone342727432", Modify Window "1ms" 2025/03/13 01:22:43 ERROR : Ignoring --no-traverse with sync 2025/03/13 01:22:43 DEBUG : Added delayed dir = "sub dir", newDst= 2025/03/13 01:22:43 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2025/03/13 01:22:43 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vawaqoj2yalo': Waiting for checks to finish 2025/03/13 01:22:43 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vawaqoj2yalo': Waiting for transfers to finish 2025/03/13 01:22:48 DEBUG : sub dir/hello world: md5 = 73984f024fce10135110adcde2ad08a6 OK 2025/03/13 01:22:48 INFO : sub dir/hello world: Copied (new) 2025/03/13 01:22:48 DEBUG : Waiting for deletions to finish 2025/03/13 01:22:49 INFO : sub dir: Set directory modification time (using DirSetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-vawaqoj2yalo'", Local "Local file system at /tmp/rclone342727432", Modify Window "1ms" 2025/03/13 01:22:54 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestSyncNoTraverse (12.43s) === RUN TestCopyWithDepth run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-vawaqoj2yalo'", Local "Local file system at /tmp/rclone342727432", Modify Window "1ms" 2025/03/13 01:22:56 DEBUG : hello world2: Need to transfer - File not found at Destination 2025/03/13 01:22:56 DEBUG : Added delayed dir = "sub dir", newDst= 2025/03/13 01:22:56 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vawaqoj2yalo': Waiting for checks to finish 2025/03/13 01:22:56 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vawaqoj2yalo': Waiting for transfers to finish 2025/03/13 01:22:57 DEBUG : hello world2: md5 = a5747b73d55b7e77e687866f103555d2 OK 2025/03/13 01:22:57 INFO : hello world2: Copied (new) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-vawaqoj2yalo'", Local "Local file system at /tmp/rclone342727432", Modify Window "1ms" --- PASS: TestCopyWithDepth (3.24s) === RUN TestCopyWithFilesFrom run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-vawaqoj2yalo'", Local "Local file system at /tmp/rclone342727432", Modify Window "1ms" 2025/03/13 01:22:59 DEBUG : potato2: Need to transfer - File not found at Destination 2025/03/13 01:22:59 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vawaqoj2yalo': Waiting for checks to finish 2025/03/13 01:22:59 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vawaqoj2yalo': Waiting for transfers to finish 2025/03/13 01:23:01 DEBUG : potato2: md5 = ddb934fb1d60da50b53a10539504a9a2 OK 2025/03/13 01:23:01 INFO : potato2: Copied (new) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-vawaqoj2yalo'", Local "Local file system at /tmp/rclone342727432", Modify Window "1ms" --- PASS: TestCopyWithFilesFrom (3.70s) === RUN TestCopyWithFilesFromAndNoTraverse run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-vawaqoj2yalo'", Local "Local file system at /tmp/rclone342727432", Modify Window "1ms" 2025/03/13 01:23:03 DEBUG : potato2: Need to transfer - File not found at Destination 2025/03/13 01:23:03 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vawaqoj2yalo': Waiting for checks to finish 2025/03/13 01:23:03 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vawaqoj2yalo': Waiting for transfers to finish 2025/03/13 01:23:04 DEBUG : potato2: md5 = 3796f21837df38823c419b7d7f41e62f OK 2025/03/13 01:23:04 INFO : potato2: Copied (new) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-vawaqoj2yalo'", Local "Local file system at /tmp/rclone342727432", Modify Window "1ms" --- PASS: TestCopyWithFilesFromAndNoTraverse (3.49s) === RUN TestCopyEmptyDirectories run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-vawaqoj2yalo'", Local "Local file system at /tmp/rclone342727432", Modify Window "1ms" 2025/03/13 01:23:06 DEBUG : sub dir2/sub sub dir2: Making directory with metadata 2025/03/13 01:23:06 INFO : sub dir2/sub sub dir2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2025/03/13 01:23:06 INFO : sub dir2: Set directory modification time (using DirSetModTime) 2025/03/13 01:23:06 INFO : sub dir: Set directory modification time (using DirSetModTime) 2025/03/13 01:23:06 DEBUG : sub dir: Making directory with metadata 2025/03/13 01:23:07 INFO : sub dir: Made directory with metadata (mtime=2001-02-03T04:05:06.499999999Z) 2025/03/13 01:23:07 DEBUG : sub dir2: Making directory with metadata 2025/03/13 01:23:09 INFO : sub dir2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2025/03/13 01:23:09 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2025/03/13 01:23:09 DEBUG : sub dir2/sub sub dir2: Making directory with metadata 2025/03/13 01:23:10 INFO : sub dir2/sub sub dir2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2025/03/13 01:23:10 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vawaqoj2yalo': Waiting for checks to finish 2025/03/13 01:23:10 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vawaqoj2yalo': Waiting for transfers to finish 2025/03/13 01:23:10 DEBUG : sub dir/hello world: md5 = 3d0c269479d909c0e6cb1a3b6d0424ba OK 2025/03/13 01:23:10 INFO : sub dir/hello world: Copied (new) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-vawaqoj2yalo'", Local "Local file system at /tmp/rclone342727432", Modify Window "1ms" 2025/03/13 01:23:14 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc: Rmdir: contains trashed file: "cv6a9uf28ngrajena8kt5ijjn0" 2025/03/13 01:23:15 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestCopyEmptyDirectories (10.11s) === RUN TestCopyNoEmptyDirectories run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-vawaqoj2yalo'", Local "Local file system at /tmp/rclone342727432", Modify Window "1ms" 2025/03/13 01:23:16 INFO : sub dir2: Making directory 2025/03/13 01:23:16 DEBUG : sub dir2/sub sub dir2: Making directory with metadata 2025/03/13 01:23:16 INFO : sub dir2/sub sub dir2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2025/03/13 01:23:16 DEBUG : Added delayed dir = "sub dir", newDst= 2025/03/13 01:23:16 DEBUG : Added delayed dir = "sub dir2", newDst= 2025/03/13 01:23:16 DEBUG : Added delayed dir = "sub dir2/sub sub dir2", newDst= 2025/03/13 01:23:16 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2025/03/13 01:23:16 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vawaqoj2yalo': Waiting for checks to finish 2025/03/13 01:23:16 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vawaqoj2yalo': Waiting for transfers to finish 2025/03/13 01:23:20 DEBUG : sub dir/hello world: md5 = 0c27ed7009ef9c6bfe5c54ad90bdac89 OK 2025/03/13 01:23:20 INFO : sub dir/hello world: Copied (new) 2025/03/13 01:23:22 INFO : sub dir: Set directory modification time (using DirSetModTime) 2025/03/13 01:23:24 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestCopyNoEmptyDirectories (8.91s) === RUN TestMoveEmptyDirectories run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-vawaqoj2yalo'", Local "Local file system at /tmp/rclone342727432", Modify Window "1ms" 2025/03/13 01:23:25 DEBUG : sub dir2: Making directory with metadata 2025/03/13 01:23:25 INFO : sub dir2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2025/03/13 01:23:25 DEBUG : sub dir: Making directory with metadata 2025/03/13 01:23:27 INFO : sub dir: Made directory with metadata (mtime=2025-03-13T01:23:25.330290506Z) 2025/03/13 01:23:27 DEBUG : sub dir2: Making directory with metadata 2025/03/13 01:23:28 INFO : sub dir2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2025/03/13 01:23:28 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2025/03/13 01:23:28 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vawaqoj2yalo': Waiting for checks to finish 2025/03/13 01:23:28 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vawaqoj2yalo': Waiting for transfers to finish 2025/03/13 01:23:30 DEBUG : sub dir/hello world: md5 = 00385593d6a4b0f9b2865bdee76b725b OK 2025/03/13 01:23:30 INFO : sub dir/hello world: Copied (new) 2025/03/13 01:23:30 INFO : sub dir/hello world: Deleted run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-vawaqoj2yalo'", Local "Local file system at /tmp/rclone342727432", Modify Window "1ms" 2025/03/13 01:23:38 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestMoveEmptyDirectories (13.89s) === RUN TestSyncNoUpdateDirModtime run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-vawaqoj2yalo'", Local "Local file system at /tmp/rclone342727432", Modify Window "1ms" 2025/03/13 01:23:39 DEBUG : sub dir no update dir modtime: Making directory with metadata 2025/03/13 01:23:39 INFO : sub dir no update dir modtime: Made directory with metadata (mtime=2001-02-03T04:05:06.499999999Z) 2025/03/13 01:23:41 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vawaqoj2yalo': Waiting for checks to finish 2025/03/13 01:23:41 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vawaqoj2yalo': Waiting for transfers to finish 2025/03/13 01:23:41 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-vawaqoj2yalo'", Local "Local file system at /tmp/rclone342727432", Modify Window "1ms" --- PASS: TestSyncNoUpdateDirModtime (4.57s) === RUN TestMoveNoEmptyDirectories run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-vawaqoj2yalo'", Local "Local file system at /tmp/rclone342727432", Modify Window "1ms" 2025/03/13 01:23:43 INFO : sub dir2: Making directory 2025/03/13 01:23:44 DEBUG : Added delayed dir = "sub dir", newDst= 2025/03/13 01:23:44 DEBUG : Added delayed dir = "sub dir2", newDst= 2025/03/13 01:23:44 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2025/03/13 01:23:44 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vawaqoj2yalo': Waiting for checks to finish 2025/03/13 01:23:44 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vawaqoj2yalo': Waiting for transfers to finish 2025/03/13 01:23:46 DEBUG : sub dir/hello world: md5 = 6da0534ab7b125328403089524b593ad OK 2025/03/13 01:23:46 INFO : sub dir/hello world: Copied (new) 2025/03/13 01:23:46 INFO : sub dir/hello world: Deleted 2025/03/13 01:23:47 INFO : sub dir: Set directory modification time (using DirSetModTime) 2025/03/13 01:23:48 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestMoveNoEmptyDirectories (5.88s) === RUN TestSyncEmptyDirectories run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-vawaqoj2yalo'", Local "Local file system at /tmp/rclone342727432", Modify Window "1ms" 2025/03/13 01:23:49 DEBUG : sub dir2: Making directory with metadata 2025/03/13 01:23:49 INFO : sub dir2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2025/03/13 01:23:49 INFO : sub dir: Set directory modification time (using DirSetModTime) 2025/03/13 01:23:49 DEBUG : sub dir: Making directory with metadata 2025/03/13 01:23:50 INFO : sub dir: Made directory with metadata (mtime=2001-02-03T04:05:06.499999999Z) 2025/03/13 01:23:50 DEBUG : sub dir2: Making directory with metadata 2025/03/13 01:23:51 INFO : sub dir2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2025/03/13 01:23:51 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2025/03/13 01:23:51 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vawaqoj2yalo': Waiting for checks to finish 2025/03/13 01:23:51 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vawaqoj2yalo': Waiting for transfers to finish 2025/03/13 01:23:52 DEBUG : sub dir/hello world: md5 = 25580e85a4f43469469b225104e9f9c4 OK 2025/03/13 01:23:52 INFO : sub dir/hello world: Copied (new) 2025/03/13 01:23:52 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-vawaqoj2yalo'", Local "Local file system at /tmp/rclone342727432", Modify Window "1ms" 2025/03/13 01:23:55 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestSyncEmptyDirectories (7.34s) === RUN TestSyncSetDelayedModTimes run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-vawaqoj2yalo'", Local "Local file system at /tmp/rclone342727432", Modify Window "1ms" sync_test.go:507: Backend doesn't have DirModTimeUpdatesOnWrite set --- SKIP: TestSyncSetDelayedModTimes (0.51s) === RUN TestSyncNoEmptyDirectories run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-vawaqoj2yalo'", Local "Local file system at /tmp/rclone342727432", Modify Window "1ms" 2025/03/13 01:23:57 INFO : sub dir2: Making directory 2025/03/13 01:23:57 DEBUG : Added delayed dir = "sub dir", newDst= 2025/03/13 01:23:57 DEBUG : Added delayed dir = "sub dir2", newDst= 2025/03/13 01:23:57 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2025/03/13 01:23:57 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vawaqoj2yalo': Waiting for checks to finish 2025/03/13 01:23:57 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vawaqoj2yalo': Waiting for transfers to finish 2025/03/13 01:23:59 DEBUG : sub dir/hello world: md5 = 49afd67334bb1014a32bf41d983b6da1 OK 2025/03/13 01:23:59 INFO : sub dir/hello world: Copied (new) 2025/03/13 01:23:59 DEBUG : Waiting for deletions to finish 2025/03/13 01:24:00 INFO : sub dir: Set directory modification time (using DirSetModTime) 2025/03/13 01:24:02 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestSyncNoEmptyDirectories (5.28s) === RUN TestServerSideCopy run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-vawaqoj2yalo'", Local "Local file system at /tmp/rclone342727432", Modify Window "1ms" 2025/03/13 01:24:05 DEBUG : sub dir/hello world: md5 = 59f9b9b8984ba5b198b222a794993b5f OK 2025/03/13 01:24:06 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-gihefac8jadu" 2025/03/13 01:24:06 DEBUG : Creating backend with remote "TestDrive:crypt/e7teib623qb0qjj4kmpcpkanle6dt51cerlk23jcvc9ko6evgkp0" sync_test.go:590: Server side copy (if possible) Encrypted drive 'TestCryptDrive:rclone-test-vawaqoj2yalo' -> Encrypted drive 'TestCryptDrive:rclone-test-gihefac8jadu' 2025/03/13 01:24:07 DEBUG : Added delayed dir = "sub dir", newDst= 2025/03/13 01:24:07 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2025/03/13 01:24:07 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gihefac8jadu': Waiting for checks to finish 2025/03/13 01:24:07 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gihefac8jadu': Waiting for transfers to finish 2025/03/13 01:24:10 INFO : sub dir/hello world: Copied (server-side copy) 2025/03/13 01:24:10 INFO : sub dir: Set directory modification time (using DirSetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-vawaqoj2yalo'", Local "Local file system at /tmp/rclone342727432", Modify Window "1ms" 2025/03/13 01:24:11 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gihefac8jadu': Purge remote 2025/03/13 01:24:13 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestServerSideCopy (11.53s) === RUN TestCopyOverSelf run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-vawaqoj2yalo'", Local "Local file system at /tmp/rclone342727432", Modify Window "1ms" 2025/03/13 01:24:16 DEBUG : sub dir/hello world: md5 = f592f5e26c678df136c05c507b6dc8ac OK 2025/03/13 01:24:17 INFO : sub dir: Set directory modification time (using SetModTime) 2025/03/13 01:24:17 DEBUG : Added delayed dir = "sub dir", newDst=sub dir 2025/03/13 01:24:17 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vawaqoj2yalo': Waiting for checks to finish 2025/03/13 01:24:17 DEBUG : sub dir/hello world: Sizes differ (src 17 vs dst 11) 2025/03/13 01:24:17 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vawaqoj2yalo': Waiting for transfers to finish 2025/03/13 01:24:18 DEBUG : sub dir/hello world: md5 = dfff08f782f19a080f72aea6ff7855a8 OK 2025/03/13 01:24:18 INFO : sub dir/hello world: Copied (replaced existing) 2025/03/13 01:24:19 INFO : sub dir: Set directory modification time (using SetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-vawaqoj2yalo'", Local "Local file system at /tmp/rclone342727432", Modify Window "1ms" 2025/03/13 01:24:21 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestCopyOverSelf (8.02s) === RUN TestServerSideCopyOverSelf run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-vawaqoj2yalo'", Local "Local file system at /tmp/rclone342727432", Modify Window "1ms" 2025/03/13 01:24:24 DEBUG : sub dir/hello world: md5 = e606bedc2634fad3b59a52fbdbb1afda OK 2025/03/13 01:24:24 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-dovagon5gico" 2025/03/13 01:24:25 DEBUG : Creating backend with remote "TestDrive:crypt/9n4mh75qc13dmv76bbe97jum47si69klg0tnap4hsb7md8ng63gg" sync_test.go:626: Server side copy (if possible) Encrypted drive 'TestCryptDrive:rclone-test-vawaqoj2yalo' -> Encrypted drive 'TestCryptDrive:rclone-test-dovagon5gico' 2025/03/13 01:24:26 DEBUG : Added delayed dir = "sub dir", newDst= 2025/03/13 01:24:26 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2025/03/13 01:24:26 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dovagon5gico': Waiting for checks to finish 2025/03/13 01:24:26 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dovagon5gico': Waiting for transfers to finish 2025/03/13 01:24:29 INFO : sub dir/hello world: Copied (server-side copy) 2025/03/13 01:24:29 INFO : sub dir: Set directory modification time (using DirSetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-vawaqoj2yalo'", Local "Local file system at /tmp/rclone342727432", Modify Window "1ms" 2025/03/13 01:24:31 DEBUG : sub dir/hello world: md5 = 330ea59773af66d16aaafb7e5846b3a5 OK 2025/03/13 01:24:32 DEBUG : sub dir: Directory modification time the same (differ by 0s, within tolerance 1ms) 2025/03/13 01:24:32 DEBUG : Added delayed dir = "sub dir", newDst=sub dir 2025/03/13 01:24:32 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dovagon5gico': Waiting for checks to finish 2025/03/13 01:24:32 DEBUG : sub dir/hello world: Sizes differ (src 17 vs dst 11) 2025/03/13 01:24:32 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dovagon5gico': Waiting for transfers to finish 2025/03/13 01:24:33 INFO : sub dir/hello world: Copied (server-side copy) 2025/03/13 01:24:34 INFO : sub dir: Set directory modification time (using SetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-vawaqoj2yalo'", Local "Local file system at /tmp/rclone342727432", Modify Window "1ms" 2025/03/13 01:24:34 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dovagon5gico': Purge remote 2025/03/13 01:24:36 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestServerSideCopyOverSelf (15.99s) === RUN TestMoveOverSelf run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-vawaqoj2yalo'", Local "Local file system at /tmp/rclone342727432", Modify Window "1ms" 2025/03/13 01:24:40 DEBUG : sub dir/hello world: md5 = f67441e85387e1844fc6b8b94b560fd6 OK 2025/03/13 01:24:41 INFO : sub dir: Set directory modification time (using SetModTime) 2025/03/13 01:24:41 DEBUG : Added delayed dir = "sub dir", newDst=sub dir 2025/03/13 01:24:42 DEBUG : sub dir/hello world: Sizes differ (src 17 vs dst 11) 2025/03/13 01:24:42 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vawaqoj2yalo': Waiting for checks to finish 2025/03/13 01:24:42 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vawaqoj2yalo': Waiting for transfers to finish 2025/03/13 01:24:43 DEBUG : sub dir/hello world: md5 = 239ee8aa026e954db16bbe34f4c32a89 OK 2025/03/13 01:24:43 INFO : sub dir/hello world: Copied (replaced existing) 2025/03/13 01:24:43 INFO : sub dir/hello world: Deleted 2025/03/13 01:24:43 INFO : sub dir: Set directory modification time (using SetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-vawaqoj2yalo'", Local "Local file system at /tmp/rclone342727432", Modify Window "1ms" 2025/03/13 01:24:45 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestMoveOverSelf (8.17s) === RUN TestServerSideMoveOverSelf run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-vawaqoj2yalo'", Local "Local file system at /tmp/rclone342727432", Modify Window "1ms" 2025/03/13 01:24:48 DEBUG : sub dir/hello world: md5 = dbd7923a75b4c8b914521f8dd6ce1fce OK 2025/03/13 01:24:49 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-juvirat1bibu" 2025/03/13 01:24:49 DEBUG : Creating backend with remote "TestDrive:crypt/der7gilchpva6o918c1m7ohshm6946k9enaqjl5dub203umuh06g" sync_test.go:671: Server side copy (if possible) Encrypted drive 'TestCryptDrive:rclone-test-vawaqoj2yalo' -> Encrypted drive 'TestCryptDrive:rclone-test-juvirat1bibu' 2025/03/13 01:24:50 DEBUG : Added delayed dir = "sub dir", newDst= 2025/03/13 01:24:50 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2025/03/13 01:24:50 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-juvirat1bibu': Waiting for checks to finish 2025/03/13 01:24:50 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-juvirat1bibu': Waiting for transfers to finish 2025/03/13 01:24:53 INFO : sub dir/hello world: Copied (server-side copy) 2025/03/13 01:24:53 INFO : sub dir: Set directory modification time (using DirSetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-vawaqoj2yalo'", Local "Local file system at /tmp/rclone342727432", Modify Window "1ms" 2025/03/13 01:24:55 DEBUG : sub dir/hello world: md5 = 6179a359a5f0c240a3eaa6c2623a6875 OK 2025/03/13 01:24:56 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-juvirat1bibu': Using server-side directory move 2025/03/13 01:24:56 INFO : Encrypted drive 'TestCryptDrive:rclone-test-juvirat1bibu': Server side directory move failed - fallback to file moves: can't copy directory - destination already exists 2025/03/13 01:24:56 DEBUG : sub dir: Directory modification time the same (differ by 0s, within tolerance 1ms) 2025/03/13 01:24:56 DEBUG : Added delayed dir = "sub dir", newDst=sub dir 2025/03/13 01:24:56 DEBUG : sub dir/hello world: Sizes differ (src 17 vs dst 11) 2025/03/13 01:24:56 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-juvirat1bibu': Waiting for checks to finish 2025/03/13 01:24:56 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-juvirat1bibu': Waiting for transfers to finish 2025/03/13 01:24:57 INFO : sub dir/hello world: Deleted 2025/03/13 01:24:57 INFO : sub dir/hello world: Moved (server-side) 2025/03/13 01:24:58 INFO : sub dir: Set directory modification time (using SetModTime) 2025/03/13 01:25:00 DEBUG : sub dir/hello world: md5 = 44d45896cb7524a5af5ff23c522fa8bb OK 2025/03/13 01:25:01 DEBUG : testing file moves 2025/03/13 01:25:01 DEBUG : sub dir: Directory modification time the same (differ by 0s, within tolerance 1ms) 2025/03/13 01:25:01 DEBUG : Added delayed dir = "sub dir", newDst=sub dir 2025/03/13 01:25:01 DEBUG : sub dir/hello world: Sizes differ (src 24 vs dst 17) 2025/03/13 01:25:01 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-juvirat1bibu': Waiting for checks to finish 2025/03/13 01:25:01 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-juvirat1bibu': Waiting for transfers to finish 2025/03/13 01:25:02 INFO : sub dir/hello world: Deleted 2025/03/13 01:25:02 INFO : sub dir/hello world: Moved (server-side) 2025/03/13 01:25:03 INFO : sub dir: Set directory modification time (using SetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-vawaqoj2yalo'", Local "Local file system at /tmp/rclone342727432", Modify Window "1ms" 2025/03/13 01:25:04 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-juvirat1bibu': Purge remote --- PASS: TestServerSideMoveOverSelf (20.60s) === RUN TestCopyAfterDelete run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-vawaqoj2yalo'", Local "Local file system at /tmp/rclone342727432", Modify Window "1ms" 2025/03/13 01:25:09 DEBUG : sub dir/hello world: md5 = d234b5a63c707342a7b0f42a25a0232b OK 2025/03/13 01:25:09 ERROR : : error listing: directory not found 2025/03/13 01:25:09 INFO : Local file system at /tmp/rclone342727432: Making directory 2025/03/13 01:25:10 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vawaqoj2yalo': Waiting for checks to finish 2025/03/13 01:25:10 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vawaqoj2yalo': Waiting for transfers to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-vawaqoj2yalo'", Local "Local file system at /tmp/rclone342727432", Modify Window "1ms" 2025/03/13 01:25:12 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestCopyAfterDelete (6.26s) === RUN TestCopyRedownload run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-vawaqoj2yalo'", Local "Local file system at /tmp/rclone342727432", Modify Window "1ms" 2025/03/13 01:25:15 DEBUG : sub dir/hello world: md5 = 4cdd5252277891e26286b659c5c921e6 OK 2025/03/13 01:25:16 DEBUG : Added delayed dir = "sub dir", newDst= 2025/03/13 01:25:16 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2025/03/13 01:25:16 DEBUG : Local file system at /tmp/rclone342727432: Waiting for checks to finish 2025/03/13 01:25:16 DEBUG : Local file system at /tmp/rclone342727432: Waiting for transfers to finish 2025/03/13 01:25:17 DEBUG : sub dir/hello world.285f0a30.partial: renamed to: sub dir/hello world 2025/03/13 01:25:17 INFO : sub dir/hello world: Copied (new) 2025/03/13 01:25:17 INFO : sub dir: Set directory modification time (using DirSetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-vawaqoj2yalo'", Local "Local file system at /tmp/rclone342727432", Modify Window "1ms" 2025/03/13 01:25:18 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestCopyRedownload (6.26s) === RUN TestSyncBasedOnCheckSum run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-vawaqoj2yalo'", Local "Local file system at /tmp/rclone342727432", Modify Window "1ms" 2025/03/13 01:25:19 DEBUG : check sum: Need to transfer - File not found at Destination 2025/03/13 01:25:19 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vawaqoj2yalo': Waiting for checks to finish 2025/03/13 01:25:19 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vawaqoj2yalo': Waiting for transfers to finish 2025/03/13 01:25:21 DEBUG : check sum: md5 = b8d9c9460f0eb369cecc5223eb3b8452 OK 2025/03/13 01:25:21 INFO : check sum: Copied (new) 2025/03/13 01:25:21 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-vawaqoj2yalo'", Local "Local file system at /tmp/rclone342727432", Modify Window "1ms" 2025/03/13 01:25:21 NOTICE: Encrypted drive 'TestCryptDrive:rclone-test-vawaqoj2yalo': --checksum is in use but the source and destination have no hashes in common; falling back to --size-only 2025/03/13 01:25:21 DEBUG : check sum: Size of src and dst objects identical 2025/03/13 01:25:21 DEBUG : check sum: Unchanged skipping 2025/03/13 01:25:21 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vawaqoj2yalo': Waiting for checks to finish 2025/03/13 01:25:21 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vawaqoj2yalo': Waiting for transfers to finish 2025/03/13 01:25:21 DEBUG : Waiting for deletions to finish 2025/03/13 01:25:21 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-vawaqoj2yalo'", Local "Local file system at /tmp/rclone342727432", Modify Window "1ms" --- PASS: TestSyncBasedOnCheckSum (4.15s) === RUN TestSyncSizeOnly run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-vawaqoj2yalo'", Local "Local file system at /tmp/rclone342727432", Modify Window "1ms" 2025/03/13 01:25:24 DEBUG : sizeonly: Need to transfer - File not found at Destination 2025/03/13 01:25:24 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vawaqoj2yalo': Waiting for checks to finish 2025/03/13 01:25:24 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vawaqoj2yalo': Waiting for transfers to finish 2025/03/13 01:25:25 DEBUG : sizeonly: md5 = 38723e4827405e357bd08a7638d888ea OK 2025/03/13 01:25:25 INFO : sizeonly: Copied (new) 2025/03/13 01:25:25 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-vawaqoj2yalo'", Local "Local file system at /tmp/rclone342727432", Modify Window "1ms" 2025/03/13 01:25:25 DEBUG : sizeonly: Sizes identical 2025/03/13 01:25:25 DEBUG : sizeonly: Unchanged skipping 2025/03/13 01:25:25 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vawaqoj2yalo': Waiting for checks to finish 2025/03/13 01:25:25 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vawaqoj2yalo': Waiting for transfers to finish 2025/03/13 01:25:25 DEBUG : Waiting for deletions to finish 2025/03/13 01:25:25 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-vawaqoj2yalo'", Local "Local file system at /tmp/rclone342727432", Modify Window "1ms" --- PASS: TestSyncSizeOnly (4.31s) === RUN TestSyncIgnoreSize run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-vawaqoj2yalo'", Local "Local file system at /tmp/rclone342727432", Modify Window "1ms" 2025/03/13 01:25:28 DEBUG : ignore-size: Need to transfer - File not found at Destination 2025/03/13 01:25:28 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vawaqoj2yalo': Waiting for checks to finish 2025/03/13 01:25:28 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vawaqoj2yalo': Waiting for transfers to finish 2025/03/13 01:25:29 DEBUG : ignore-size: md5 = 2260961ee119b9982656eb9542ab5e97 OK 2025/03/13 01:25:29 INFO : ignore-size: Copied (new) 2025/03/13 01:25:29 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-vawaqoj2yalo'", Local "Local file system at /tmp/rclone342727432", Modify Window "1ms" 2025/03/13 01:25:30 DEBUG : ignore-size: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/03/13 01:25:30 DEBUG : ignore-size: Unchanged skipping 2025/03/13 01:25:30 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vawaqoj2yalo': Waiting for checks to finish 2025/03/13 01:25:30 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vawaqoj2yalo': Waiting for transfers to finish 2025/03/13 01:25:30 DEBUG : Waiting for deletions to finish 2025/03/13 01:25:30 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-vawaqoj2yalo'", Local "Local file system at /tmp/rclone342727432", Modify Window "1ms" --- PASS: TestSyncIgnoreSize (4.10s) === RUN TestSyncIgnoreTimes run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-vawaqoj2yalo'", Local "Local file system at /tmp/rclone342727432", Modify Window "1ms" 2025/03/13 01:25:33 DEBUG : existing: md5 = 22c1cfb70e329d2f8b39d6bac4e548b1 OK 2025/03/13 01:25:34 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vawaqoj2yalo': Waiting for checks to finish 2025/03/13 01:25:34 DEBUG : existing: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/03/13 01:25:34 DEBUG : existing: Unchanged skipping 2025/03/13 01:25:34 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vawaqoj2yalo': Waiting for transfers to finish 2025/03/13 01:25:34 DEBUG : Waiting for deletions to finish 2025/03/13 01:25:34 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-vawaqoj2yalo'", Local "Local file system at /tmp/rclone342727432", Modify Window "1ms" 2025/03/13 01:25:34 DEBUG : existing: Transferring unconditionally as --ignore-times is in use 2025/03/13 01:25:34 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vawaqoj2yalo': Waiting for checks to finish 2025/03/13 01:25:34 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vawaqoj2yalo': Waiting for transfers to finish 2025/03/13 01:25:35 DEBUG : existing: md5 = 1fa903cf40b5aefb5a96673c3246aa1a OK 2025/03/13 01:25:35 INFO : existing: Copied (replaced existing) 2025/03/13 01:25:35 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-vawaqoj2yalo'", Local "Local file system at /tmp/rclone342727432", Modify Window "1ms" --- PASS: TestSyncIgnoreTimes (5.38s) === RUN TestSyncIgnoreExisting run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-vawaqoj2yalo'", Local "Local file system at /tmp/rclone342727432", Modify Window "1ms" 2025/03/13 01:25:37 DEBUG : existing: Need to transfer - File not found at Destination 2025/03/13 01:25:37 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vawaqoj2yalo': Waiting for checks to finish 2025/03/13 01:25:37 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vawaqoj2yalo': Waiting for transfers to finish 2025/03/13 01:25:39 DEBUG : existing: md5 = 6b000d2a4ea973c3a6846ea7248127a4 OK 2025/03/13 01:25:39 INFO : existing: Copied (new) 2025/03/13 01:25:39 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-vawaqoj2yalo'", Local "Local file system at /tmp/rclone342727432", Modify Window "1ms" 2025/03/13 01:25:39 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vawaqoj2yalo': Waiting for checks to finish 2025/03/13 01:25:39 DEBUG : existing: Destination exists, skipping 2025/03/13 01:25:39 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vawaqoj2yalo': Waiting for transfers to finish 2025/03/13 01:25:39 DEBUG : Waiting for deletions to finish 2025/03/13 01:25:39 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-vawaqoj2yalo'", Local "Local file system at /tmp/rclone342727432", Modify Window "1ms" --- PASS: TestSyncIgnoreExisting (4.27s) === RUN TestSyncIgnoreErrors run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-vawaqoj2yalo'", Local "Local file system at /tmp/rclone342727432", Modify Window "1ms" 2025/03/13 01:25:44 DEBUG : b/potato: md5 = 6c761e1c2e4d5efbfd591a51e5ea7f49 OK 2025/03/13 01:25:46 DEBUG : c/non empty space: md5 = fd3847b37599ccb28b71587d80cb88fa OK 2025/03/13 01:25:46 INFO : d: Making directory 2025/03/13 01:25:48 DEBUG : Added delayed dir = "a", newDst= 2025/03/13 01:25:48 INFO : c: Set directory modification time (using SetModTime) 2025/03/13 01:25:48 DEBUG : Added delayed dir = "c", newDst=c 2025/03/13 01:25:48 DEBUG : a/potato2: Need to transfer - File not found at Destination 2025/03/13 01:25:48 DEBUG : c/non empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/03/13 01:25:48 DEBUG : c/non empty space: Unchanged skipping 2025/03/13 01:25:50 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vawaqoj2yalo': Waiting for checks to finish 2025/03/13 01:25:50 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vawaqoj2yalo': Waiting for transfers to finish 2025/03/13 01:25:51 DEBUG : a/potato2: md5 = 9c23778168509419ea3c356a7204f297 OK 2025/03/13 01:25:51 INFO : a/potato2: Copied (new) 2025/03/13 01:25:51 DEBUG : Waiting for deletions to finish 2025/03/13 01:25:51 INFO : b/potato: Deleted 2025/03/13 01:25:52 INFO : a: Set directory modification time (using DirSetModTime) 2025/03/13 01:25:52 INFO : d: Removing directory 2025/03/13 01:25:52 INFO : b: Removing directory 2025/03/13 01:25:53 DEBUG : 32d8ua6196mc1r7qkfog53rkg0: Rmdir: contains trashed file: "2m507n64kafsi59v9q71r281a4" 2025/03/13 01:25:53 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vawaqoj2yalo': deleted 2 directories run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-vawaqoj2yalo'", Local "Local file system at /tmp/rclone342727432", Modify Window "1ms" 2025/03/13 01:25:55 DEBUG : 3i9du405pfogq3ncai6pg7ouio: Rmdir: contains trashed file: "982d3pss7t5pn0il16r2foj31s" 2025/03/13 01:25:56 DEBUG : 2bsvlrk2ne1lfitm6tttcu0qt8: Rmdir: contains trashed file: "89l8renevh3mji1c8r1p7qn6tg" --- PASS: TestSyncIgnoreErrors (15.67s) === RUN TestSyncAfterChangingModtimeOnly run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-vawaqoj2yalo'", Local "Local file system at /tmp/rclone342727432", Modify Window "1ms" 2025/03/13 01:25:58 DEBUG : empty space: md5 = c6618db9639b3ab2f5212c47bbf3348e OK 2025/03/13 01:25:59 DEBUG : empty space: Modification times differ by -95456h54m52.624456789s: 2011-12-25 12:59:59.123456789 +0000 UTC, 2001-02-03 04:05:06.499 +0000 UTC 2025/03/13 01:25:59 NOTICE: empty space: Skipped copy as --dry-run is set (size 1) 2025/03/13 01:25:59 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vawaqoj2yalo': Waiting for checks to finish 2025/03/13 01:25:59 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vawaqoj2yalo': Waiting for transfers to finish 2025/03/13 01:25:59 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-vawaqoj2yalo'", Local "Local file system at /tmp/rclone342727432", Modify Window "1ms" 2025/03/13 01:25:59 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vawaqoj2yalo': Waiting for checks to finish 2025/03/13 01:25:59 DEBUG : empty space: Modification times differ by -95456h54m52.624456789s: 2011-12-25 12:59:59.123456789 +0000 UTC, 2001-02-03 04:05:06.499 +0000 UTC 2025/03/13 01:25:59 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vawaqoj2yalo': Waiting for transfers to finish 2025/03/13 01:26:01 DEBUG : empty space: md5 = f5b7c746f3d79690c5ed5141e7e3aa5f OK 2025/03/13 01:26:01 INFO : empty space: Copied (replaced existing) 2025/03/13 01:26:01 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-vawaqoj2yalo'", Local "Local file system at /tmp/rclone342727432", Modify Window "1ms" --- PASS: TestSyncAfterChangingModtimeOnly (5.66s) === RUN TestSyncAfterChangingModtimeOnlyWithNoUpdateModTime run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-vawaqoj2yalo'", Local "Local file system at /tmp/rclone342727432", Modify Window "1ms" sync_test.go:1016: Can't check this if no hashes supported --- PASS: TestSyncAfterChangingModtimeOnlyWithNoUpdateModTime (0.48s) === RUN TestSyncDoesntUpdateModtime run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-vawaqoj2yalo'", Local "Local file system at /tmp/rclone342727432", Modify Window "1ms" 2025/03/13 01:26:05 DEBUG : foo: md5 = c5e46df6334b469271576f3758e8cc23 OK 2025/03/13 01:26:05 DEBUG : foo: Modification times differ by -95456h54m52.624456789s: 2011-12-25 12:59:59.123456789 +0000 UTC, 2001-02-03 04:05:06.499 +0000 UTC 2025/03/13 01:26:05 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vawaqoj2yalo': Waiting for checks to finish 2025/03/13 01:26:05 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vawaqoj2yalo': Waiting for transfers to finish 2025/03/13 01:26:06 DEBUG : foo: md5 = ec2a79e7759df384880b9f12599b1e5f OK 2025/03/13 01:26:06 INFO : foo: Copied (replaced existing) 2025/03/13 01:26:06 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-vawaqoj2yalo'", Local "Local file system at /tmp/rclone342727432", Modify Window "1ms" --- PASS: TestSyncDoesntUpdateModtime (4.92s) === RUN TestSyncAfterAddingAFile run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-vawaqoj2yalo'", Local "Local file system at /tmp/rclone342727432", Modify Window "1ms" 2025/03/13 01:26:09 DEBUG : empty space: md5 = 46d120627837aeee64778eacf3252bd7 OK 2025/03/13 01:26:10 DEBUG : potato: Need to transfer - File not found at Destination 2025/03/13 01:26:10 DEBUG : empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/03/13 01:26:10 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vawaqoj2yalo': Waiting for checks to finish 2025/03/13 01:26:10 DEBUG : empty space: Unchanged skipping 2025/03/13 01:26:10 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vawaqoj2yalo': Waiting for transfers to finish 2025/03/13 01:26:11 DEBUG : potato: md5 = f072400c992598d65e7cdf7b086e50a4 OK 2025/03/13 01:26:11 INFO : potato: Copied (new) 2025/03/13 01:26:11 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-vawaqoj2yalo'", Local "Local file system at /tmp/rclone342727432", Modify Window "1ms" --- PASS: TestSyncAfterAddingAFile (5.43s) === RUN TestSyncAfterChangingFilesSizeOnly run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-vawaqoj2yalo'", Local "Local file system at /tmp/rclone342727432", Modify Window "1ms" 2025/03/13 01:26:15 DEBUG : potato: md5 = 9d9c8843e1befaa6d559c6f45db57e26 OK 2025/03/13 01:26:15 DEBUG : potato: Sizes differ (src 21 vs dst 60) 2025/03/13 01:26:15 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vawaqoj2yalo': Waiting for checks to finish 2025/03/13 01:26:15 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vawaqoj2yalo': Waiting for transfers to finish 2025/03/13 01:26:17 DEBUG : potato: md5 = 5f9a25f11fad1caed38b5e849c1eaaf4 OK 2025/03/13 01:26:17 INFO : potato: Copied (replaced existing) 2025/03/13 01:26:17 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-vawaqoj2yalo'", Local "Local file system at /tmp/rclone342727432", Modify Window "1ms" --- PASS: TestSyncAfterChangingFilesSizeOnly (4.64s) === RUN TestSyncAfterChangingContentsOnly run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-vawaqoj2yalo'", Local "Local file system at /tmp/rclone342727432", Modify Window "1ms" 2025/03/13 01:26:20 DEBUG : potato: md5 = 1f28dab48e23ea01fc5c9ab79467d615 OK 2025/03/13 01:26:20 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vawaqoj2yalo': Waiting for checks to finish 2025/03/13 01:26:20 DEBUG : potato: Modification times differ by 119h59m59.876543211s: 2011-12-25 12:59:59.123456789 +0000 UTC, 2011-12-30 12:59:59 +0000 UTC 2025/03/13 01:26:20 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vawaqoj2yalo': Waiting for transfers to finish 2025/03/13 01:26:21 DEBUG : potato: md5 = b437abe0f8f185972388b90dbd699889 OK 2025/03/13 01:26:21 INFO : potato: Copied (replaced existing) 2025/03/13 01:26:21 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-vawaqoj2yalo'", Local "Local file system at /tmp/rclone342727432", Modify Window "1ms" --- PASS: TestSyncAfterChangingContentsOnly (4.67s) === RUN TestSyncAfterRemovingAFileAndAddingAFileDryRun run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-vawaqoj2yalo'", Local "Local file system at /tmp/rclone342727432", Modify Window "1ms" 2025/03/13 01:26:24 DEBUG : potato: md5 = 0973d4f7613ca16e6b60d7a3301b4721 OK 2025/03/13 01:26:25 DEBUG : empty space: md5 = 5056e86a78fcb868b224df8142fad1ac OK 2025/03/13 01:26:26 DEBUG : potato2: Need to transfer - File not found at Destination 2025/03/13 01:26:26 NOTICE: potato2: Skipped copy as --dry-run is set (size 60) 2025/03/13 01:26:26 DEBUG : empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/03/13 01:26:26 DEBUG : empty space: Unchanged skipping 2025/03/13 01:26:26 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vawaqoj2yalo': Waiting for checks to finish 2025/03/13 01:26:26 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vawaqoj2yalo': Waiting for transfers to finish 2025/03/13 01:26:26 DEBUG : Waiting for deletions to finish 2025/03/13 01:26:26 NOTICE: potato: Skipped delete as --dry-run is set (size 21) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-vawaqoj2yalo'", Local "Local file system at /tmp/rclone342727432", Modify Window "1ms" --- PASS: TestSyncAfterRemovingAFileAndAddingAFileDryRun (4.86s) === RUN TestSyncAfterRemovingAFileAndAddingAFile run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-vawaqoj2yalo'", Local "Local file system at /tmp/rclone342727432", Modify Window "1ms" 2025/03/13 01:26:29 DEBUG : potato: md5 = 3a2d9bc0805bce26db3759fb5596de90 OK 2025/03/13 01:26:30 DEBUG : empty space: md5 = 25a67d5a48cc37514bc5c68a21a6c588 OK 2025/03/13 01:26:31 DEBUG : potato2: Need to transfer - File not found at Destination 2025/03/13 01:26:31 DEBUG : empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/03/13 01:26:31 DEBUG : empty space: Unchanged skipping 2025/03/13 01:26:31 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vawaqoj2yalo': Waiting for checks to finish 2025/03/13 01:26:31 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vawaqoj2yalo': Waiting for transfers to finish 2025/03/13 01:26:32 DEBUG : potato2: md5 = 44930ded68a056c7ccc5e77e8d9bbf5b OK 2025/03/13 01:26:32 INFO : potato2: Copied (new) 2025/03/13 01:26:32 DEBUG : Waiting for deletions to finish 2025/03/13 01:26:33 INFO : potato: Deleted run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-vawaqoj2yalo'", Local "Local file system at /tmp/rclone342727432", Modify Window "1ms" --- PASS: TestSyncAfterRemovingAFileAndAddingAFile (7.07s) === RUN TestSyncAfterRemovingAFileAndAddingAFileSubDir run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-vawaqoj2yalo'", Local "Local file system at /tmp/rclone342727432", Modify Window "1ms" 2025/03/13 01:26:37 DEBUG : b/potato: md5 = b8a1341e08c2cc1c36b034c43daee01d OK 2025/03/13 01:26:39 DEBUG : c/non empty space: md5 = 353b61b52c2d5e4c667c753600e39ccf OK 2025/03/13 01:26:39 INFO : d: Making directory 2025/03/13 01:26:40 INFO : d/e: Making directory 2025/03/13 01:26:42 DEBUG : Added delayed dir = "a", newDst= 2025/03/13 01:26:42 INFO : c: Set directory modification time (using SetModTime) 2025/03/13 01:26:42 DEBUG : Added delayed dir = "c", newDst=c 2025/03/13 01:26:42 DEBUG : a/potato2: Need to transfer - File not found at Destination 2025/03/13 01:26:42 DEBUG : c/non empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/03/13 01:26:42 DEBUG : c/non empty space: Unchanged skipping 2025/03/13 01:26:43 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vawaqoj2yalo': Waiting for checks to finish 2025/03/13 01:26:43 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vawaqoj2yalo': Waiting for transfers to finish 2025/03/13 01:26:44 DEBUG : a/potato2: md5 = 661eec920cffd2032a190ad37dd0563c OK 2025/03/13 01:26:44 INFO : a/potato2: Copied (new) 2025/03/13 01:26:44 DEBUG : Waiting for deletions to finish 2025/03/13 01:26:45 INFO : b/potato: Deleted 2025/03/13 01:26:45 INFO : a: Set directory modification time (using DirSetModTime) 2025/03/13 01:26:45 INFO : d/e: Removing directory 2025/03/13 01:26:46 INFO : d: Removing directory 2025/03/13 01:26:46 DEBUG : ka6id8d20d3s5ktapedlphgta8: Rmdir: contains trashed file: "r8sppajuabeak3sbgj2ak8vuf8" 2025/03/13 01:26:47 INFO : b: Removing directory 2025/03/13 01:26:47 DEBUG : 32d8ua6196mc1r7qkfog53rkg0: Rmdir: contains trashed file: "2m507n64kafsi59v9q71r281a4" 2025/03/13 01:26:47 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vawaqoj2yalo': deleted 3 directories run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-vawaqoj2yalo'", Local "Local file system at /tmp/rclone342727432", Modify Window "1ms" 2025/03/13 01:26:49 DEBUG : 3i9du405pfogq3ncai6pg7ouio: Rmdir: contains trashed file: "982d3pss7t5pn0il16r2foj31s" 2025/03/13 01:26:50 DEBUG : 2bsvlrk2ne1lfitm6tttcu0qt8: Rmdir: contains trashed file: "89l8renevh3mji1c8r1p7qn6tg" --- PASS: TestSyncAfterRemovingAFileAndAddingAFileSubDir (16.64s) === RUN TestSyncAfterRemovingAFileAndAddingAFileSubDirWithErrors run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-vawaqoj2yalo'", Local "Local file system at /tmp/rclone342727432", Modify Window "1ms" 2025/03/13 01:26:53 DEBUG : b/potato: md5 = 191b80faeea6a0b08dac1429f98510fb OK 2025/03/13 01:26:56 DEBUG : c/non empty space: md5 = 7cc278570c1d2414204508f89bd32f21 OK 2025/03/13 01:26:56 INFO : d: Making directory 2025/03/13 01:26:57 DEBUG : Added delayed dir = "a", newDst= 2025/03/13 01:26:58 INFO : c: Set directory modification time (using SetModTime) 2025/03/13 01:26:58 DEBUG : Added delayed dir = "c", newDst=c 2025/03/13 01:26:58 DEBUG : a/potato2: Need to transfer - File not found at Destination 2025/03/13 01:26:58 DEBUG : c/non empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/03/13 01:26:58 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vawaqoj2yalo': Waiting for checks to finish 2025/03/13 01:26:58 DEBUG : c/non empty space: Unchanged skipping 2025/03/13 01:26:58 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vawaqoj2yalo': Waiting for transfers to finish 2025/03/13 01:27:00 DEBUG : a/potato2: md5 = e04ab703dcdc5b1a5135706acfc7f9fa OK 2025/03/13 01:27:00 INFO : a/potato2: Copied (new) 2025/03/13 01:27:00 ERROR : Encrypted drive 'TestCryptDrive:rclone-test-vawaqoj2yalo': not deleting files as there were IO errors 2025/03/13 01:27:01 INFO : a: Set directory modification time (using DirSetModTime) 2025/03/13 01:27:01 ERROR : Encrypted drive 'TestCryptDrive:rclone-test-vawaqoj2yalo': not deleting directories as there were IO errors run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-vawaqoj2yalo'", Local "Local file system at /tmp/rclone342727432", Modify Window "1ms" 2025/03/13 01:27:04 DEBUG : 3i9du405pfogq3ncai6pg7ouio: Rmdir: contains trashed file: "982d3pss7t5pn0il16r2foj31s" 2025/03/13 01:27:05 DEBUG : 32d8ua6196mc1r7qkfog53rkg0: Rmdir: contains trashed file: "2m507n64kafsi59v9q71r281a4" 2025/03/13 01:27:05 DEBUG : 2bsvlrk2ne1lfitm6tttcu0qt8: Rmdir: contains trashed file: "89l8renevh3mji1c8r1p7qn6tg" --- PASS: TestSyncAfterRemovingAFileAndAddingAFileSubDirWithErrors (15.10s) === RUN TestSyncDeleteAfter --- PASS: TestSyncDeleteAfter (0.00s) === RUN TestSyncDeleteDuring run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-vawaqoj2yalo'", Local "Local file system at /tmp/rclone342727432", Modify Window "1ms" 2025/03/13 01:27:08 DEBUG : potato: md5 = ff0ef5e50541f53cabcde5dc6a953ca2 OK 2025/03/13 01:27:09 DEBUG : empty space: md5 = 11b463b8bbcf2555aab1b6b07a2bbbb3 OK 2025/03/13 01:27:10 DEBUG : Waiting for deletions to finish 2025/03/13 01:27:10 DEBUG : potato2: Need to transfer - File not found at Destination 2025/03/13 01:27:10 DEBUG : empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/03/13 01:27:10 DEBUG : empty space: Unchanged skipping 2025/03/13 01:27:10 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vawaqoj2yalo': Waiting for checks to finish 2025/03/13 01:27:10 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vawaqoj2yalo': Waiting for transfers to finish 2025/03/13 01:27:10 INFO : potato: Deleted 2025/03/13 01:27:11 DEBUG : potato2: md5 = a2f876025dca40d6e09b11adcc7120b9 OK 2025/03/13 01:27:11 INFO : potato2: Copied (new) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-vawaqoj2yalo'", Local "Local file system at /tmp/rclone342727432", Modify Window "1ms" --- PASS: TestSyncDeleteDuring (7.04s) === RUN TestSyncDeleteBefore run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-vawaqoj2yalo'", Local "Local file system at /tmp/rclone342727432", Modify Window "1ms" 2025/03/13 01:27:15 DEBUG : potato: md5 = f736a40f3897cf676d9143c988d0edcc OK 2025/03/13 01:27:16 DEBUG : empty space: md5 = 636a02631d9b81e8c8e5fba0a3348c64 OK 2025/03/13 01:27:17 DEBUG : Waiting for deletions to finish 2025/03/13 01:27:17 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vawaqoj2yalo': Waiting for checks to finish 2025/03/13 01:27:17 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vawaqoj2yalo': Waiting for transfers to finish 2025/03/13 01:27:17 INFO : potato: Deleted 2025/03/13 01:27:18 DEBUG : potato2: Need to transfer - File not found at Destination 2025/03/13 01:27:18 DEBUG : empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/03/13 01:27:18 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vawaqoj2yalo': Waiting for checks to finish 2025/03/13 01:27:18 DEBUG : empty space: Unchanged skipping 2025/03/13 01:27:18 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vawaqoj2yalo': Waiting for transfers to finish 2025/03/13 01:27:19 DEBUG : potato2: md5 = 46a8042e8dadf65de45b2c2e2fb4f9a8 OK 2025/03/13 01:27:19 INFO : potato2: Copied (new) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-vawaqoj2yalo'", Local "Local file system at /tmp/rclone342727432", Modify Window "1ms" --- PASS: TestSyncDeleteBefore (7.76s) === RUN TestCopyDeleteBefore run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-vawaqoj2yalo'", Local "Local file system at /tmp/rclone342727432", Modify Window "1ms" 2025/03/13 01:27:23 DEBUG : potato: md5 = b5999a0de959f5833005bfd9088fd7ff OK 2025/03/13 01:27:23 DEBUG : potato2: Need to transfer - File not found at Destination 2025/03/13 01:27:23 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vawaqoj2yalo': Waiting for checks to finish 2025/03/13 01:27:23 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vawaqoj2yalo': Waiting for transfers to finish 2025/03/13 01:27:25 DEBUG : potato2: md5 = e3d708f4c9f8858a1681bd899d519483 OK 2025/03/13 01:27:25 INFO : potato2: Copied (new) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-vawaqoj2yalo'", Local "Local file system at /tmp/rclone342727432", Modify Window "1ms" --- PASS: TestCopyDeleteBefore (5.26s) === RUN TestSyncWithExclude run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-vawaqoj2yalo'", Local "Local file system at /tmp/rclone342727432", Modify Window "1ms" 2025/03/13 01:27:28 DEBUG : potato2: md5 = c91f8b97ef87de2ee782b72f0aafb01c OK 2025/03/13 01:27:29 DEBUG : empty space: md5 = 0851228c90932301f278857372395646 OK 2025/03/13 01:27:30 DEBUG : enormous: Excluded (Size Filter) 2025/03/13 01:27:30 DEBUG : enormous: Excluded 2025/03/13 01:27:30 DEBUG : potato2: Excluded (Size Filter) 2025/03/13 01:27:30 DEBUG : potato2: Excluded 2025/03/13 01:27:30 DEBUG : potato2: Excluded (Size Filter) 2025/03/13 01:27:30 DEBUG : potato2: Excluded 2025/03/13 01:27:30 DEBUG : empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/03/13 01:27:30 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vawaqoj2yalo': Waiting for checks to finish 2025/03/13 01:27:30 DEBUG : empty space: Unchanged skipping 2025/03/13 01:27:30 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vawaqoj2yalo': Waiting for transfers to finish 2025/03/13 01:27:30 DEBUG : Waiting for deletions to finish 2025/03/13 01:27:30 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-vawaqoj2yalo'", Local "Local file system at /tmp/rclone342727432", Modify Window "1ms" 2025/03/13 01:27:30 DEBUG : enormous: Excluded (Size Filter) 2025/03/13 01:27:30 DEBUG : enormous: Excluded 2025/03/13 01:27:30 DEBUG : potato2: Excluded (Size Filter) 2025/03/13 01:27:30 DEBUG : potato2: Excluded 2025/03/13 01:27:30 DEBUG : potato2: Excluded (Size Filter) 2025/03/13 01:27:30 DEBUG : potato2: Excluded 2025/03/13 01:27:30 DEBUG : empty space: Size and modification time the same (differ by 456.789µs, within tolerance 1ms) 2025/03/13 01:27:30 DEBUG : empty space: Unchanged skipping 2025/03/13 01:27:30 DEBUG : Local file system at /tmp/rclone342727432: Waiting for checks to finish 2025/03/13 01:27:30 DEBUG : Local file system at /tmp/rclone342727432: Waiting for transfers to finish 2025/03/13 01:27:30 DEBUG : Waiting for deletions to finish 2025/03/13 01:27:30 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-vawaqoj2yalo'", Local "Local file system at /tmp/rclone342727432", Modify Window "1ms" --- PASS: TestSyncWithExclude (6.33s) === RUN TestSyncWithExcludeAndDeleteExcluded run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-vawaqoj2yalo'", Local "Local file system at /tmp/rclone342727432", Modify Window "1ms" 2025/03/13 01:27:34 DEBUG : potato2: md5 = 8d9559d93616a4d467a20c320ebb7df9 OK 2025/03/13 01:27:36 DEBUG : empty space: md5 = 30acbd1e11322bf5be89fcec124443d5 OK 2025/03/13 01:27:37 DEBUG : enormous: md5 = e2e65f63fdef698568ea5519902ae3fa OK 2025/03/13 01:27:38 DEBUG : enormous: Excluded (Size Filter) 2025/03/13 01:27:38 DEBUG : enormous: Excluded 2025/03/13 01:27:38 DEBUG : potato2: Excluded (Size Filter) 2025/03/13 01:27:38 DEBUG : potato2: Excluded 2025/03/13 01:27:38 DEBUG : empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/03/13 01:27:38 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vawaqoj2yalo': Waiting for checks to finish 2025/03/13 01:27:38 DEBUG : empty space: Unchanged skipping 2025/03/13 01:27:38 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vawaqoj2yalo': Waiting for transfers to finish 2025/03/13 01:27:38 DEBUG : Waiting for deletions to finish 2025/03/13 01:27:39 INFO : enormous: Deleted 2025/03/13 01:27:39 INFO : potato2: Deleted 2025/03/13 01:27:39 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-vawaqoj2yalo'", Local "Local file system at /tmp/rclone342727432", Modify Window "1ms" 2025/03/13 01:27:39 DEBUG : empty space: Size and modification time the same (differ by 456.789µs, within tolerance 1ms) 2025/03/13 01:27:39 DEBUG : empty space: Unchanged skipping 2025/03/13 01:27:39 DEBUG : Local file system at /tmp/rclone342727432: Waiting for checks to finish 2025/03/13 01:27:39 DEBUG : Local file system at /tmp/rclone342727432: Waiting for transfers to finish 2025/03/13 01:27:39 DEBUG : Waiting for deletions to finish 2025/03/13 01:27:39 INFO : enormous: Deleted 2025/03/13 01:27:39 INFO : potato2: Deleted 2025/03/13 01:27:39 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-vawaqoj2yalo'", Local "Local file system at /tmp/rclone342727432", Modify Window "1ms" --- PASS: TestSyncWithExcludeAndDeleteExcluded (8.01s) === RUN TestSyncWithUpdateOlder run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-vawaqoj2yalo'", Local "Local file system at /tmp/rclone342727432", Modify Window "1ms" 2025/03/13 01:27:42 DEBUG : one: md5 = fb15017fb4aa48f022e10284eb7d535b OK 2025/03/13 01:27:44 DEBUG : two: md5 = d7706e99a119f8e93bcc464509c912e7 OK 2025/03/13 01:27:45 DEBUG : three: md5 = ae45ddd4cb45ba5ab86b11ed3b8c8d1e OK 2025/03/13 01:27:47 DEBUG : four: md5 = 3cb7e285c36c865dbcf7a3c1a6b5cf04 OK 2025/03/13 01:27:47 DEBUG : five: Need to transfer - File not found at Destination 2025/03/13 01:27:47 DEBUG : four: Sizes differ (src 4 vs dst 8) 2025/03/13 01:27:47 DEBUG : one: Destination is newer than source, skipping 2025/03/13 01:27:47 DEBUG : three: Sizes identical 2025/03/13 01:27:47 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vawaqoj2yalo': Waiting for checks to finish 2025/03/13 01:27:47 DEBUG : four: Destination mod time is within 1s of source but files differ, transferring 2025/03/13 01:27:47 DEBUG : three: Destination mod time is within 1s of source and files identical, skipping 2025/03/13 01:27:47 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vawaqoj2yalo': Waiting for transfers to finish 2025/03/13 01:27:48 DEBUG : four: md5 = 3ddc0ba517e68493ec2e264854c5ab9d OK 2025/03/13 01:27:48 INFO : four: Copied (replaced existing) 2025/03/13 01:27:48 DEBUG : two: md5 = 000fd406b50a40f09bc781094e8e0ef8 OK 2025/03/13 01:27:48 INFO : two: Copied (replaced existing) 2025/03/13 01:27:49 DEBUG : five: md5 = 5e11fe50632bb74ecbbc68f8adf1b9b0 OK 2025/03/13 01:27:49 INFO : five: Copied (new) 2025/03/13 01:27:49 DEBUG : Waiting for deletions to finish sync_test.go:1449: Skip test with --checksum as no hashes supported --- PASS: TestSyncWithUpdateOlder (10.88s) === 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-vawaqoj2yalo'", Local "Local file system at /tmp/rclone342727432", Modify Window "1ms" sync_test.go:1538: Can track renames: false 2025/03/13 01:27:52 ERROR : Encrypted drive 'TestCryptDrive:rclone-test-vawaqoj2yalo': Ignoring --track-renames as the source and destination do not have a common hash 2025/03/13 01:27:52 DEBUG : potato: Need to transfer - File not found at Destination 2025/03/13 01:27:52 DEBUG : yam: Need to transfer - File not found at Destination 2025/03/13 01:27:52 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vawaqoj2yalo': Waiting for checks to finish 2025/03/13 01:27:52 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vawaqoj2yalo': Waiting for transfers to finish 2025/03/13 01:27:53 DEBUG : yam: md5 = 37747d8cd214548739dd22046a0c6477 OK 2025/03/13 01:27:53 INFO : yam: Copied (new) 2025/03/13 01:27:53 DEBUG : potato: md5 = a315576f224a96d3e5fe007cfcfcb91e OK 2025/03/13 01:27:53 INFO : potato: Copied (new) 2025/03/13 01:27:53 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-vawaqoj2yalo'", Local "Local file system at /tmp/rclone342727432", Modify Window "1ms" 2025/03/13 01:27:54 ERROR : Encrypted drive 'TestCryptDrive:rclone-test-vawaqoj2yalo': Ignoring --track-renames as the source and destination do not have a common hash 2025/03/13 01:27:54 DEBUG : yaml: Need to transfer - File not found at Destination 2025/03/13 01:27:54 DEBUG : potato: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/03/13 01:27:54 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vawaqoj2yalo': Waiting for checks to finish 2025/03/13 01:27:54 DEBUG : potato: Unchanged skipping 2025/03/13 01:27:54 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vawaqoj2yalo': Waiting for transfers to finish 2025/03/13 01:27:55 DEBUG : yaml: md5 = 89d428f48224f261d36e7e923b564ccf OK 2025/03/13 01:27:55 INFO : yaml: Copied (new) 2025/03/13 01:27:55 DEBUG : Waiting for deletions to finish 2025/03/13 01:27:56 INFO : yam: Deleted run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-vawaqoj2yalo'", Local "Local file system at /tmp/rclone342727432", Modify Window "1ms" --- PASS: TestSyncWithTrackRenames (6.42s) === RUN TestParseRenamesStrategyModtime --- PASS: TestParseRenamesStrategyModtime (0.00s) === RUN TestRenamesStrategyModtime --- PASS: TestRenamesStrategyModtime (0.00s) === RUN TestSyncWithTrackRenamesStrategyModtime run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-vawaqoj2yalo'", Local "Local file system at /tmp/rclone342727432", Modify Window "1ms" sync_test.go:1610: Can track renames: true 2025/03/13 01:27:58 INFO : Encrypted drive 'TestCryptDrive:rclone-test-vawaqoj2yalo': Making map for --track-renames 2025/03/13 01:27:58 INFO : Encrypted drive 'TestCryptDrive:rclone-test-vawaqoj2yalo': Finished making map for --track-renames 2025/03/13 01:27:58 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vawaqoj2yalo': Waiting for checks to finish 2025/03/13 01:27:58 DEBUG : potato: Need to transfer - No matching file found at Destination 2025/03/13 01:27:58 DEBUG : yam: Need to transfer - No matching file found at Destination 2025/03/13 01:27:58 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vawaqoj2yalo': Waiting for renames to finish 2025/03/13 01:27:58 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vawaqoj2yalo': Waiting for transfers to finish 2025/03/13 01:28:00 DEBUG : yam: md5 = 4822aa25a7532427213076f38de20060 OK 2025/03/13 01:28:00 INFO : yam: Copied (new) 2025/03/13 01:28:00 DEBUG : potato: md5 = 1a0f80d6a4e95287d67f61f995e21517 OK 2025/03/13 01:28:00 INFO : potato: Copied (new) 2025/03/13 01:28:00 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-vawaqoj2yalo'", Local "Local file system at /tmp/rclone342727432", Modify Window "1ms" 2025/03/13 01:28:00 DEBUG : potato: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/03/13 01:28:00 INFO : Encrypted drive 'TestCryptDrive:rclone-test-vawaqoj2yalo': Making map for --track-renames 2025/03/13 01:28:00 INFO : Encrypted drive 'TestCryptDrive:rclone-test-vawaqoj2yalo': Finished making map for --track-renames 2025/03/13 01:28:00 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vawaqoj2yalo': Waiting for checks to finish 2025/03/13 01:28:00 DEBUG : potato: Unchanged skipping 2025/03/13 01:28:00 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vawaqoj2yalo': Waiting for renames to finish 2025/03/13 01:28:01 INFO : yam: Moved (server-side) to: yaml 2025/03/13 01:28:01 INFO : yaml: Renamed from "yam" 2025/03/13 01:28:01 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vawaqoj2yalo': Waiting for transfers to finish 2025/03/13 01:28:01 DEBUG : Waiting for deletions to finish 2025/03/13 01:28:01 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-vawaqoj2yalo'", Local "Local file system at /tmp/rclone342727432", Modify Window "1ms" --- PASS: TestSyncWithTrackRenamesStrategyModtime (5.37s) === RUN TestSyncWithTrackRenamesStrategyLeaf run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-vawaqoj2yalo'", Local "Local file system at /tmp/rclone342727432", Modify Window "1ms" sync_test.go:1649: Can track renames: true 2025/03/13 01:28:04 DEBUG : Added delayed dir = "sub", newDst= 2025/03/13 01:28:04 INFO : Encrypted drive 'TestCryptDrive:rclone-test-vawaqoj2yalo': Making map for --track-renames 2025/03/13 01:28:04 INFO : Encrypted drive 'TestCryptDrive:rclone-test-vawaqoj2yalo': Finished making map for --track-renames 2025/03/13 01:28:04 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vawaqoj2yalo': Waiting for checks to finish 2025/03/13 01:28:04 DEBUG : potato: Need to transfer - No matching file found at Destination 2025/03/13 01:28:04 DEBUG : sub/yam: Need to transfer - No matching file found at Destination 2025/03/13 01:28:04 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vawaqoj2yalo': Waiting for renames to finish 2025/03/13 01:28:04 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vawaqoj2yalo': Waiting for transfers to finish 2025/03/13 01:28:06 DEBUG : potato: md5 = 7db49ab0d360370e910f2a7b1a3396b2 OK 2025/03/13 01:28:06 INFO : potato: Copied (new) 2025/03/13 01:28:06 DEBUG : sub/yam: md5 = a1ce1dcd70d72d7d6a22b9fcded427cd OK 2025/03/13 01:28:06 INFO : sub/yam: Copied (new) 2025/03/13 01:28:06 DEBUG : Waiting for deletions to finish 2025/03/13 01:28:07 INFO : sub: Set directory modification time (using DirSetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-vawaqoj2yalo'", Local "Local file system at /tmp/rclone342727432", Modify Window "1ms" 2025/03/13 01:28:07 DEBUG : potato: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/03/13 01:28:07 DEBUG : potato: Unchanged skipping 2025/03/13 01:28:08 INFO : sub: Set directory modification time (using SetModTime) 2025/03/13 01:28:08 DEBUG : Added delayed dir = "sub", newDst=sub 2025/03/13 01:28:08 INFO : Encrypted drive 'TestCryptDrive:rclone-test-vawaqoj2yalo': Making map for --track-renames 2025/03/13 01:28:08 INFO : Encrypted drive 'TestCryptDrive:rclone-test-vawaqoj2yalo': Finished making map for --track-renames 2025/03/13 01:28:08 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vawaqoj2yalo': Waiting for checks to finish 2025/03/13 01:28:08 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vawaqoj2yalo': Waiting for renames to finish 2025/03/13 01:28:09 INFO : sub/yam: Moved (server-side) to: yam 2025/03/13 01:28:09 INFO : yam: Renamed from "sub/yam" 2025/03/13 01:28:09 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vawaqoj2yalo': Waiting for transfers to finish 2025/03/13 01:28:09 DEBUG : Waiting for deletions to finish 2025/03/13 01:28:09 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-vawaqoj2yalo'", Local "Local file system at /tmp/rclone342727432", Modify Window "1ms" --- PASS: TestSyncWithTrackRenamesStrategyLeaf (9.11s) === RUN TestServerSideMoveLocal run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-vawaqoj2yalo'", Local "Local file system at /tmp/rclone342727432", Modify Window "1ms" 2025/03/13 01:28:13 DEBUG : Creating backend with remote "/tmp/rclone342727432/dir1" 2025/03/13 01:28:13 DEBUG : Config file has changed externally - reloading 2025/03/13 01:28:13 DEBUG : Creating backend with remote "/tmp/rclone342727432/dir2" 2025/03/13 01:28:13 DEBUG : Local file system at /tmp/rclone342727432/dir2: Using server-side directory move 2025/03/13 01:28:13 INFO : Local file system at /tmp/rclone342727432/dir2: Server side directory move failed - fallback to file moves: can't copy directory - destination already exists 2025/03/13 01:28:13 DEBUG : file1.txt: Need to transfer - File not found at Destination 2025/03/13 01:28:13 DEBUG : Local file system at /tmp/rclone342727432/dir2: Waiting for checks to finish 2025/03/13 01:28:13 DEBUG : Local file system at /tmp/rclone342727432/dir2: Waiting for transfers to finish 2025/03/13 01:28:13 INFO : file1.txt: Moved (server-side) --- PASS: TestServerSideMoveLocal (0.45s) === RUN TestMoveWithDeleteEmptySrcDirs run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-vawaqoj2yalo'", Local "Local file system at /tmp/rclone342727432", Modify Window "1ms" 2025/03/13 01:28:13 DEBUG : Added delayed dir = "nested", newDst= 2025/03/13 01:28:13 DEBUG : Added delayed dir = "sub dir", newDst= 2025/03/13 01:28:13 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2025/03/13 01:28:13 DEBUG : Added delayed dir = "nested/sub dir", newDst= 2025/03/13 01:28:13 DEBUG : nested/sub dir/file: Need to transfer - File not found at Destination 2025/03/13 01:28:13 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vawaqoj2yalo': Waiting for checks to finish 2025/03/13 01:28:13 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vawaqoj2yalo': Waiting for transfers to finish 2025/03/13 01:28:16 DEBUG : sub dir/hello world: md5 = 1a46f1e0c6763f51a271aa899388e4ca OK 2025/03/13 01:28:16 INFO : sub dir/hello world: Copied (new) 2025/03/13 01:28:16 INFO : sub dir/hello world: Deleted 2025/03/13 01:28:17 DEBUG : nested/sub dir/file: md5 = b7184241916b67f36b23df2e4aa532d0 OK 2025/03/13 01:28:17 INFO : nested/sub dir/file: Copied (new) 2025/03/13 01:28:17 INFO : nested/sub dir/file: Deleted 2025/03/13 01:28:18 INFO : nested/sub dir: Set directory modification time (using DirSetModTime) 2025/03/13 01:28:18 INFO : nested: Set directory modification time (using DirSetModTime) 2025/03/13 01:28:18 INFO : sub dir: Set directory modification time (using DirSetModTime) 2025/03/13 01:28:18 INFO : sub dir: Removing directory 2025/03/13 01:28:18 INFO : nested/sub dir: Removing directory 2025/03/13 01:28:18 INFO : nested: Removing directory 2025/03/13 01:28:18 DEBUG : Local file system at /tmp/rclone342727432: deleted 3 directories run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-vawaqoj2yalo'", Local "Local file system at /tmp/rclone342727432", Modify Window "1ms" 2025/03/13 01:28:21 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" 2025/03/13 01:28:22 DEBUG : 37qp6d1gohacv723ij3brofbu8/14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "ftp4kuv8se7tqduu6pmmcvjsmk" 2025/03/13 01:28:22 DEBUG : 37qp6d1gohacv723ij3brofbu8: Rmdir: contains trashed file: "14begaa36ih249fgrnfk6nulg0" --- PASS: TestMoveWithDeleteEmptySrcDirs (10.35s) === RUN TestMoveWithoutDeleteEmptySrcDirs run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-vawaqoj2yalo'", Local "Local file system at /tmp/rclone342727432", Modify Window "1ms" 2025/03/13 01:28:24 DEBUG : Added delayed dir = "nested", newDst= 2025/03/13 01:28:24 DEBUG : Added delayed dir = "sub dir", newDst= 2025/03/13 01:28:24 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2025/03/13 01:28:24 DEBUG : Added delayed dir = "nested/sub dir", newDst= 2025/03/13 01:28:24 DEBUG : nested/sub dir/file: Need to transfer - File not found at Destination 2025/03/13 01:28:24 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vawaqoj2yalo': Waiting for checks to finish 2025/03/13 01:28:24 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vawaqoj2yalo': Waiting for transfers to finish 2025/03/13 01:28:26 DEBUG : sub dir/hello world: md5 = e3bc796116f9b70c4459e85f6ae3007e OK 2025/03/13 01:28:26 INFO : sub dir/hello world: Copied (new) 2025/03/13 01:28:26 INFO : sub dir/hello world: Deleted 2025/03/13 01:28:28 DEBUG : nested/sub dir/file: md5 = ea6ee884b276789a6369bba0f7459833 OK 2025/03/13 01:28:28 INFO : nested/sub dir/file: Copied (new) 2025/03/13 01:28:28 INFO : nested/sub dir/file: Deleted 2025/03/13 01:28:28 INFO : nested/sub dir: Set directory modification time (using DirSetModTime) 2025/03/13 01:28:29 INFO : sub dir: Set directory modification time (using DirSetModTime) 2025/03/13 01:28:29 INFO : nested: Set directory modification time (using DirSetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-vawaqoj2yalo'", Local "Local file system at /tmp/rclone342727432", Modify Window "1ms" 2025/03/13 01:28:31 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" 2025/03/13 01:28:32 DEBUG : 37qp6d1gohacv723ij3brofbu8/14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "ftp4kuv8se7tqduu6pmmcvjsmk" 2025/03/13 01:28:33 DEBUG : 37qp6d1gohacv723ij3brofbu8: Rmdir: contains trashed file: "14begaa36ih249fgrnfk6nulg0" --- PASS: TestMoveWithoutDeleteEmptySrcDirs (10.36s) === RUN TestMoveWithIgnoreExisting run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-vawaqoj2yalo'", Local "Local file system at /tmp/rclone342727432", Modify Window "1ms" 2025/03/13 01:28:34 DEBUG : existing: Need to transfer - File not found at Destination 2025/03/13 01:28:34 DEBUG : existing-b: Need to transfer - File not found at Destination 2025/03/13 01:28:34 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vawaqoj2yalo': Waiting for checks to finish 2025/03/13 01:28:34 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vawaqoj2yalo': Waiting for transfers to finish 2025/03/13 01:28:35 DEBUG : existing-b: md5 = 2804080b07d2346e84286561316a3c03 OK 2025/03/13 01:28:35 INFO : existing-b: Copied (new) 2025/03/13 01:28:35 INFO : existing-b: Deleted 2025/03/13 01:28:36 DEBUG : existing: md5 = 874682afe8d4614556332e824c4925e5 OK 2025/03/13 01:28:36 INFO : existing: Copied (new) 2025/03/13 01:28:36 INFO : existing: Deleted 2025/03/13 01:28:36 DEBUG : existing: Destination exists, skipping 2025/03/13 01:28:36 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vawaqoj2yalo': Waiting for checks to finish 2025/03/13 01:28:36 DEBUG : existing: Not removing source file as destination file exists and --ignore-existing is set 2025/03/13 01:28:36 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vawaqoj2yalo': Waiting for transfers to finish 2025/03/13 01:28:36 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-vawaqoj2yalo'", Local "Local file system at /tmp/rclone342727432", Modify Window "1ms" --- PASS: TestMoveWithIgnoreExisting (4.28s) === RUN TestServerSideMove run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-vawaqoj2yalo'", Local "Local file system at /tmp/rclone342727432", Modify Window "1ms" 2025/03/13 01:28:38 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-hihudon1xaga" 2025/03/13 01:28:38 DEBUG : Creating backend with remote "TestDrive:crypt/vra6be3mrcaphipe2od1m13ev8ghd27u0rrs342avvah8c5dn7r0" 2025/03/13 01:28:41 DEBUG : potato2: md5 = d9f791042cf91028934bb96777df3b1e OK 2025/03/13 01:28:42 DEBUG : empty space: md5 = 2929387a2a94f2dde94509c782a91492 OK 2025/03/13 01:28:43 DEBUG : potato3: md5 = dd29252439da51a8c31d40720ad3bfe1 OK sync_test.go:1705: Server side move (if possible) Encrypted drive 'TestCryptDrive:rclone-test-vawaqoj2yalo' -> Encrypted drive 'TestCryptDrive:rclone-test-hihudon1xaga' 2025/03/13 01:28:46 DEBUG : empty space: md5 = 61d96b42b6e6c8e77532ebdead2c9a59 OK 2025/03/13 01:28:47 DEBUG : potato3: md5 = 66198d8e9ca27b96b12fa5d610180536 OK 2025/03/13 01:28:48 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hihudon1xaga': Using server-side directory move 2025/03/13 01:28:48 INFO : Encrypted drive 'TestCryptDrive:rclone-test-hihudon1xaga': Server side directory move failed - fallback to file moves: can't copy directory - destination already exists 2025/03/13 01:28:48 DEBUG : potato2: Need to transfer - File not found at Destination 2025/03/13 01:28:48 DEBUG : empty space: Size and modification time the same (differ by 0s, within tolerance 1ms) 2025/03/13 01:28:48 DEBUG : empty space: Unchanged skipping 2025/03/13 01:28:48 DEBUG : potato3: Sizes differ (src 68 vs dst 60) 2025/03/13 01:28:48 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hihudon1xaga': Waiting for checks to finish 2025/03/13 01:28:48 INFO : empty space: Deleted 2025/03/13 01:28:48 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hihudon1xaga': Waiting for transfers to finish 2025/03/13 01:28:48 INFO : potato3: Deleted 2025/03/13 01:28:48 INFO : potato2: Moved (server-side) 2025/03/13 01:28:49 INFO : potato3: Moved (server-side) 2025/03/13 01:28:49 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-cafuxob4vuro" 2025/03/13 01:28:49 DEBUG : Creating backend with remote "TestDrive:crypt/g6nibqt1148el9sb57965lplep3fac1i8ddmhvdadpb843seaa3g" 2025/03/13 01:28:50 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-cafuxob4vuro': Using server-side directory move 2025/03/13 01:28:51 INFO : Encrypted drive 'TestCryptDrive:rclone-test-cafuxob4vuro': Server side directory move succeeded 2025/03/13 01:28:52 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-cafuxob4vuro': Purge remote 2025/03/13 01:28:53 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hihudon1xaga': Purge remote 2025/03/13 01:28:53 NOTICE: purge failed: directory not found --- PASS: TestServerSideMove (15.09s) === RUN TestServerSideMoveWithFilter run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-vawaqoj2yalo'", Local "Local file system at /tmp/rclone342727432", Modify Window "1ms" 2025/03/13 01:28:53 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-zuronus0daki" 2025/03/13 01:28:53 DEBUG : Creating backend with remote "TestDrive:crypt/idd24pmp295al2eu2hs6l57v81f6er4fjlmgrlbdns1co54up4qg" 2025/03/13 01:28:56 DEBUG : potato2: md5 = 95eebc1ed33f767b78242c155c986913 OK 2025/03/13 01:28:57 DEBUG : empty space: md5 = 967ea8d056c3bace48829005de77ebd6 OK 2025/03/13 01:28:59 DEBUG : potato3: md5 = 7f8f7bf9db0f4777de2ebf6fa9c6a3c3 OK sync_test.go:1705: Server side move (if possible) Encrypted drive 'TestCryptDrive:rclone-test-vawaqoj2yalo' -> Encrypted drive 'TestCryptDrive:rclone-test-zuronus0daki' 2025/03/13 01:29:01 DEBUG : empty space: md5 = 4a3cd5b363d1f72340da568bbf55ce55 OK 2025/03/13 01:29:03 DEBUG : potato3: md5 = ca84824deba255bd710a461f3fde91f3 OK 2025/03/13 01:29:03 DEBUG : empty space: Excluded (Size Filter) 2025/03/13 01:29:03 DEBUG : empty space: Excluded 2025/03/13 01:29:03 DEBUG : empty space: Excluded (Size Filter) 2025/03/13 01:29:03 DEBUG : empty space: Excluded 2025/03/13 01:29:03 DEBUG : potato2: Need to transfer - File not found at Destination 2025/03/13 01:29:03 DEBUG : potato3: Sizes differ (src 68 vs dst 60) 2025/03/13 01:29:03 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zuronus0daki': Waiting for checks to finish 2025/03/13 01:29:03 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zuronus0daki': Waiting for transfers to finish 2025/03/13 01:29:04 INFO : potato3: Deleted 2025/03/13 01:29:04 INFO : potato2: Moved (server-side) 2025/03/13 01:29:04 INFO : potato3: Moved (server-side) 2025/03/13 01:29:05 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-piselop6gefi" 2025/03/13 01:29:05 DEBUG : Creating backend with remote "TestDrive:crypt/874i38g8k89psa9q8vtq04je9dlejeo3mfcps0derl1ldj9mor40" 2025/03/13 01:29:06 DEBUG : empty space: Excluded (Size Filter) 2025/03/13 01:29:06 DEBUG : empty space: Excluded 2025/03/13 01:29:06 DEBUG : potato2: Need to transfer - File not found at Destination 2025/03/13 01:29:06 DEBUG : potato3: Need to transfer - File not found at Destination 2025/03/13 01:29:06 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-piselop6gefi': Waiting for checks to finish 2025/03/13 01:29:06 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-piselop6gefi': Waiting for transfers to finish 2025/03/13 01:29:08 INFO : potato2: Moved (server-side) 2025/03/13 01:29:09 INFO : potato3: Moved (server-side) 2025/03/13 01:29:09 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-piselop6gefi': Purge remote 2025/03/13 01:29:10 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zuronus0daki': Purge remote --- PASS: TestServerSideMoveWithFilter (17.89s) === RUN TestServerSideMoveDeleteEmptySourceDirs run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-vawaqoj2yalo'", Local "Local file system at /tmp/rclone342727432", Modify Window "1ms" 2025/03/13 01:29:11 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-wopuyuk3mara" 2025/03/13 01:29:11 DEBUG : Creating backend with remote "TestDrive:crypt/8pv93re2fsqbkmb41tn0lc0gdm0gd9pufpmvjr3r1pc6hit792k0" 2025/03/13 01:29:14 DEBUG : potato2: md5 = ac5f744e0b15ba2b966ce7ccb90d4c40 OK 2025/03/13 01:29:15 DEBUG : empty space: md5 = 1b9ddccef9091fcab2868d249dc745ef OK 2025/03/13 01:29:16 DEBUG : potato3: md5 = 11cf78c1b4de328ff35bf74c7cfa908a OK 2025/03/13 01:29:16 INFO : tomatoDir: Making directory sync_test.go:1705: Server side move (if possible) Encrypted drive 'TestCryptDrive:rclone-test-vawaqoj2yalo' -> Encrypted drive 'TestCryptDrive:rclone-test-wopuyuk3mara' 2025/03/13 01:29:20 DEBUG : empty space: md5 = 5e407dedaac1b8015f647b930aa78275 OK 2025/03/13 01:29:21 DEBUG : potato3: md5 = 33d36626933a6549f17a5c6a3547eb42 OK 2025/03/13 01:29:22 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wopuyuk3mara': Using server-side directory move 2025/03/13 01:29:22 INFO : Encrypted drive 'TestCryptDrive:rclone-test-wopuyuk3mara': Server side directory move failed - fallback to file moves: can't copy directory - destination already exists 2025/03/13 01:29:22 DEBUG : potato2: Need to transfer - File not found at Destination 2025/03/13 01:29:22 DEBUG : Added delayed dir = "tomatoDir", newDst= 2025/03/13 01:29:22 DEBUG : empty space: Size and modification time the same (differ by 0s, within tolerance 1ms) 2025/03/13 01:29:22 DEBUG : empty space: Unchanged skipping 2025/03/13 01:29:22 DEBUG : potato3: Sizes differ (src 68 vs dst 60) 2025/03/13 01:29:22 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wopuyuk3mara': Waiting for checks to finish 2025/03/13 01:29:22 INFO : empty space: Deleted 2025/03/13 01:29:22 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wopuyuk3mara': Waiting for transfers to finish 2025/03/13 01:29:22 INFO : potato3: Deleted 2025/03/13 01:29:22 INFO : potato2: Moved (server-side) 2025/03/13 01:29:23 INFO : potato3: Moved (server-side) 2025/03/13 01:29:23 INFO : tomatoDir: Removing directory 2025/03/13 01:29:24 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vawaqoj2yalo': deleted 1 directories 2025/03/13 01:29:24 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-vudeqow4koho" 2025/03/13 01:29:24 DEBUG : Creating backend with remote "TestDrive:crypt/n0jnkjh5sert0q2emto66eogq155sohhuj2pubs1ifrgiocsddsg" 2025/03/13 01:29:25 INFO : tomatoDir: Making directory 2025/03/13 01:29:26 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vudeqow4koho': Using server-side directory move 2025/03/13 01:29:27 INFO : Encrypted drive 'TestCryptDrive:rclone-test-vudeqow4koho': Server side directory move succeeded 2025/03/13 01:29:28 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vudeqow4koho': Purge remote 2025/03/13 01:29:29 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wopuyuk3mara': Purge remote 2025/03/13 01:29:29 NOTICE: purge failed: directory not found --- PASS: TestServerSideMoveDeleteEmptySourceDirs (18.52s) === RUN TestServerSideMoveOverlap run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-vawaqoj2yalo'", Local "Local file system at /tmp/rclone342727432", Modify Window "1ms" sync_test.go:1910: Skipping test as remote supports DirMove --- SKIP: TestServerSideMoveOverlap (0.51s) === RUN TestSyncOverlap run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-vawaqoj2yalo'", Local "Local file system at /tmp/rclone342727432", Modify Window "1ms" 2025/03/13 01:29:30 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-vawaqoj2yalo/rclone-sync-test" 2025/03/13 01:29:30 DEBUG : Creating backend with remote "TestDrive:crypt/bi93ndoe3d0009gfdvhp48majuk0hb7ragk7jqa0ephthkp8fgq0/i7355aa0sb89uagn75vfjqr6s3e3e1h2et8in57abn1fe8qfego0" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-vawaqoj2yalo'", Local "Local file system at /tmp/rclone342727432", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-vawaqoj2yalo'", Local "Local file system at /tmp/rclone342727432", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-vawaqoj2yalo'", Local "Local file system at /tmp/rclone342727432", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-vawaqoj2yalo'", Local "Local file system at /tmp/rclone342727432", Modify Window "1ms" --- PASS: TestSyncOverlap (3.89s) === RUN TestSyncOverlapWithFilter run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-vawaqoj2yalo'", Local "Local file system at /tmp/rclone342727432", Modify Window "1ms" 2025/03/13 01:29:34 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-vawaqoj2yalo/rclone-sync-test" 2025/03/13 01:29:34 DEBUG : Creating backend with remote "TestDrive:crypt/bi93ndoe3d0009gfdvhp48majuk0hb7ragk7jqa0ephthkp8fgq0/i7355aa0sb89uagn75vfjqr6s3e3e1h2et8in57abn1fe8qfego0" 2025/03/13 01:29:36 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-vawaqoj2yalo/rclone-sync-test-include/layer2" 2025/03/13 01:29:36 DEBUG : Creating backend with remote "TestDrive:crypt/bi93ndoe3d0009gfdvhp48majuk0hb7ragk7jqa0ephthkp8fgq0/khf2vlblvnbf9ftevqm0htmss73hj1j5a7q328e4ohrgs7e2loe0/n01jpl9202nn9ec1rb75h0f1c4" 2025/03/13 01:29:39 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-vawaqoj2yalo/rclone-sync-test-ignore-file" 2025/03/13 01:29:40 DEBUG : Creating backend with remote "TestDrive:crypt/bi93ndoe3d0009gfdvhp48majuk0hb7ragk7jqa0ephthkp8fgq0/kmf11jujl9uha3tjganvgpkn45bu778hb5vb5riug1c26b38k7sg" 2025/03/13 01:29:44 DEBUG : rclone-sync-test-ignore-file/.ignore: md5 = 2090af4ccff9d77963c76d9cd6f5bd79 OK 2025/03/13 01:29:45 DEBUG : rclone-sync-test-ignore-file: Excluded 2025/03/13 01:29:45 DEBUG : rclone-sync-test: Excluded 2025/03/13 01:29:45 DEBUG : Added delayed dir = "rclone-sync-test-include", newDst= 2025/03/13 01:29:46 DEBUG : rclone-sync-test-include/layer2: Excluded 2025/03/13 01:29:46 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vawaqoj2yalo/rclone-sync-test': Waiting for checks to finish 2025/03/13 01:29:46 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vawaqoj2yalo/rclone-sync-test': Waiting for transfers to finish 2025/03/13 01:29:46 DEBUG : Waiting for deletions to finish 2025/03/13 01:29:46 INFO : There was nothing to transfer 2025/03/13 01:29:46 DEBUG : rclone-sync-test-ignore-file: Excluded 2025/03/13 01:29:47 DEBUG : rclone-sync-test: Excluded 2025/03/13 01:29:47 DEBUG : rclone-sync-test-include/layer2: Excluded 2025/03/13 01:29:47 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vawaqoj2yalo': Waiting for checks to finish 2025/03/13 01:29:47 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vawaqoj2yalo': Waiting for transfers to finish 2025/03/13 01:29:47 DEBUG : Waiting for deletions to finish 2025/03/13 01:29:47 INFO : rclone-sync-test-include: Removing directory 2025/03/13 01:29:48 DEBUG : khf2vlblvnbf9ftevqm0htmss73hj1j5a7q328e4ohrgs7e2loe0: Rmdir: contains file: "n01jpl9202nn9ec1rb75h0f1c4" 2025/03/13 01:29:48 DEBUG : rclone-sync-test-include: Failed to Rmdir: directory not empty 2025/03/13 01:29:48 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vawaqoj2yalo': failed to delete 1 directories 2025/03/13 01:29:48 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-vawaqoj2yalo'", Local "Local file system at /tmp/rclone342727432", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-vawaqoj2yalo'", Local "Local file system at /tmp/rclone342727432", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-vawaqoj2yalo'", Local "Local file system at /tmp/rclone342727432", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-vawaqoj2yalo'", Local "Local file system at /tmp/rclone342727432", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-vawaqoj2yalo'", Local "Local file system at /tmp/rclone342727432", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-vawaqoj2yalo'", Local "Local file system at /tmp/rclone342727432", Modify Window "1ms" 2025/03/13 01:29:48 DEBUG : rclone-sync-test-ignore-file: Excluded 2025/03/13 01:29:49 DEBUG : rclone-sync-test: Excluded 2025/03/13 01:29:49 DEBUG : Added delayed dir = "rclone-sync-test-include", newDst= 2025/03/13 01:29:49 DEBUG : rclone-sync-test-include/layer2: Excluded 2025/03/13 01:29:49 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vawaqoj2yalo/rclone-sync-test-include/layer2': Waiting for checks to finish 2025/03/13 01:29:49 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vawaqoj2yalo/rclone-sync-test-include/layer2': Waiting for transfers to finish 2025/03/13 01:29:49 DEBUG : Waiting for deletions to finish 2025/03/13 01:29:49 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-vawaqoj2yalo'", Local "Local file system at /tmp/rclone342727432", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-vawaqoj2yalo'", Local "Local file system at /tmp/rclone342727432", Modify Window "1ms" 2025/03/13 01:29:50 DEBUG : rclone-sync-test-ignore-file: Excluded 2025/03/13 01:29:51 DEBUG : rclone-sync-test: Excluded 2025/03/13 01:29:51 DEBUG : rclone-sync-test-include/layer2: Excluded 2025/03/13 01:29:51 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vawaqoj2yalo': Waiting for checks to finish 2025/03/13 01:29:51 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vawaqoj2yalo': Waiting for transfers to finish 2025/03/13 01:29:51 DEBUG : Waiting for deletions to finish 2025/03/13 01:29:51 INFO : rclone-sync-test-include: Removing directory 2025/03/13 01:29:51 DEBUG : khf2vlblvnbf9ftevqm0htmss73hj1j5a7q328e4ohrgs7e2loe0: Rmdir: contains file: "n01jpl9202nn9ec1rb75h0f1c4" 2025/03/13 01:29:51 DEBUG : rclone-sync-test-include: Failed to Rmdir: directory not empty 2025/03/13 01:29:51 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vawaqoj2yalo': failed to delete 1 directories 2025/03/13 01:29:51 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-vawaqoj2yalo'", Local "Local file system at /tmp/rclone342727432", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-vawaqoj2yalo'", Local "Local file system at /tmp/rclone342727432", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-vawaqoj2yalo'", Local "Local file system at /tmp/rclone342727432", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-vawaqoj2yalo'", Local "Local file system at /tmp/rclone342727432", Modify Window "1ms" 2025/03/13 01:29:52 DEBUG : : Excluded 2025/03/13 01:29:52 DEBUG : rclone-sync-test-ignore-file: Excluded 2025/03/13 01:29:53 DEBUG : rclone-sync-test: Excluded 2025/03/13 01:29:53 DEBUG : Added delayed dir = "rclone-sync-test-include", newDst= 2025/03/13 01:29:53 DEBUG : rclone-sync-test-include/layer2: Excluded 2025/03/13 01:29:53 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vawaqoj2yalo/rclone-sync-test-ignore-file': Waiting for checks to finish 2025/03/13 01:29:53 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vawaqoj2yalo/rclone-sync-test-ignore-file': Waiting for transfers to finish 2025/03/13 01:29:53 DEBUG : Waiting for deletions to finish 2025/03/13 01:29:53 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-vawaqoj2yalo'", Local "Local file system at /tmp/rclone342727432", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-vawaqoj2yalo'", Local "Local file system at /tmp/rclone342727432", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-vawaqoj2yalo'", Local "Local file system at /tmp/rclone342727432", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-vawaqoj2yalo'", Local "Local file system at /tmp/rclone342727432", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-vawaqoj2yalo'", Local "Local file system at /tmp/rclone342727432", Modify Window "1ms" 2025/03/13 01:29:55 DEBUG : khf2vlblvnbf9ftevqm0htmss73hj1j5a7q328e4ohrgs7e2loe0: Rmdir: contains trashed file: "n01jpl9202nn9ec1rb75h0f1c4" 2025/03/13 01:29:57 DEBUG : kmf11jujl9uha3tjganvgpkn45bu778hb5vb5riug1c26b38k7sg: Rmdir: contains trashed file: "i0t74httmdlljg425j6tg570d8" --- PASS: TestSyncOverlapWithFilter (32.11s) === RUN TestSyncCompareDest run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-vawaqoj2yalo'", Local "Local file system at /tmp/rclone342727432", Modify Window "1ms" 2025/03/13 01:30:06 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-vawaqoj2yalo/dst" 2025/03/13 01:30:06 DEBUG : Creating backend with remote "TestDrive:crypt/bi93ndoe3d0009gfdvhp48majuk0hb7ragk7jqa0ephthkp8fgq0/31u3jie661vd5p8j7rtc3hgbh0" 2025/03/13 01:30:08 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-vawaqoj2yalo/CompareDest" 2025/03/13 01:30:08 DEBUG : Creating backend with remote "TestDrive:crypt/bi93ndoe3d0009gfdvhp48majuk0hb7ragk7jqa0ephthkp8fgq0/gveqi14airsml4bgu7krj116o8" 2025/03/13 01:30:10 DEBUG : one: Need to transfer - File not found at Destination 2025/03/13 01:30:10 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vawaqoj2yalo/dst': Waiting for checks to finish 2025/03/13 01:30:10 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vawaqoj2yalo/dst': Waiting for transfers to finish 2025/03/13 01:30:12 DEBUG : one: md5 = 4dcbe69175d0e94a3bf026fd538788b5 OK 2025/03/13 01:30:12 INFO : one: Copied (new) 2025/03/13 01:30:12 DEBUG : Waiting for deletions to finish 2025/03/13 01:30:14 DEBUG : one: Sizes differ (src 5 vs dst 3) 2025/03/13 01:30:14 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vawaqoj2yalo/dst': Waiting for checks to finish 2025/03/13 01:30:14 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vawaqoj2yalo/dst': Waiting for transfers to finish 2025/03/13 01:30:15 DEBUG : one: md5 = 1e79c108469835e39cb4e0d374e0c324 OK 2025/03/13 01:30:15 INFO : one: Copied (replaced existing) 2025/03/13 01:30:15 DEBUG : Waiting for deletions to finish 2025/03/13 01:30:17 DEBUG : dst/one: md5 = 79058db6222057e268d579199bc4d416 OK 2025/03/13 01:30:19 DEBUG : CompareDest/one: md5 = 668810f642967ef8a342c28da50116a2 OK 2025/03/13 01:30:20 DEBUG : one: Sizes differ (src 5 vs dst 3) 2025/03/13 01:30:20 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vawaqoj2yalo/dst': Waiting for checks to finish 2025/03/13 01:30:21 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/03/13 01:30:21 DEBUG : one: Destination found in --compare-dest, skipping 2025/03/13 01:30:21 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vawaqoj2yalo/dst': Waiting for transfers to finish 2025/03/13 01:30:21 DEBUG : Waiting for deletions to finish 2025/03/13 01:30:21 INFO : There was nothing to transfer 2025/03/13 01:30:22 DEBUG : CompareDest/two: md5 = 79ab40897d48d46bb2e134e21c0324ec OK 2025/03/13 01:30:23 DEBUG : two: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/03/13 01:30:23 DEBUG : two: Destination found in --compare-dest, skipping 2025/03/13 01:30:23 DEBUG : one: Sizes differ (src 5 vs dst 3) 2025/03/13 01:30:23 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vawaqoj2yalo/dst': Waiting for checks to finish 2025/03/13 01:30:24 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/03/13 01:30:24 DEBUG : one: Destination found in --compare-dest, skipping 2025/03/13 01:30:24 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vawaqoj2yalo/dst': Waiting for transfers to finish 2025/03/13 01:30:24 DEBUG : Waiting for deletions to finish 2025/03/13 01:30:24 INFO : There was nothing to transfer 2025/03/13 01:30:25 DEBUG : two: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/03/13 01:30:25 DEBUG : two: Destination found in --compare-dest, skipping 2025/03/13 01:30:25 DEBUG : one: Sizes differ (src 5 vs dst 3) 2025/03/13 01:30:25 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vawaqoj2yalo/dst': Waiting for checks to finish 2025/03/13 01:30:25 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/03/13 01:30:25 DEBUG : one: Destination found in --compare-dest, skipping 2025/03/13 01:30:25 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vawaqoj2yalo/dst': Waiting for transfers to finish 2025/03/13 01:30:25 DEBUG : Waiting for deletions to finish 2025/03/13 01:30:25 INFO : There was nothing to transfer sync_test.go:2175: No hash on uploaded file so skipping compare timestamp test 2025/03/13 01:30:26 DEBUG : two: Sizes differ (src 5 vs dst 3) 2025/03/13 01:30:26 DEBUG : two: Need to transfer - File not found at Destination 2025/03/13 01:30:26 DEBUG : one: Sizes differ (src 5 vs dst 3) 2025/03/13 01:30:26 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vawaqoj2yalo/dst': Waiting for checks to finish 2025/03/13 01:30:27 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/03/13 01:30:27 DEBUG : one: Destination found in --compare-dest, skipping 2025/03/13 01:30:27 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vawaqoj2yalo/dst': Waiting for transfers to finish 2025/03/13 01:30:28 DEBUG : two: md5 = 0875a5b3b181232d4e22091a86f023ed OK 2025/03/13 01:30:28 INFO : two: Copied (new) 2025/03/13 01:30:28 DEBUG : Waiting for deletions to finish 2025/03/13 01:30:31 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k" 2025/03/13 01:30:31 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" 2025/03/13 01:30:32 DEBUG : gveqi14airsml4bgu7krj116o8: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" 2025/03/13 01:30:32 DEBUG : gveqi14airsml4bgu7krj116o8: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k" --- PASS: TestSyncCompareDest (26.21s) === RUN TestSyncMultipleCompareDest run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-vawaqoj2yalo'", Local "Local file system at /tmp/rclone342727432", Modify Window "1ms" 2025/03/13 01:30:34 DEBUG : pre-dest1/1: md5 = b9a188248376a08c68b99d9a468f69bc OK 2025/03/13 01:30:37 DEBUG : pre-dest2/2: md5 = 164699d04cdee59ed9381eea912fa785 OK 2025/03/13 01:30:37 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-vawaqoj2yalo/dest" 2025/03/13 01:30:37 DEBUG : Creating backend with remote "TestDrive:crypt/bi93ndoe3d0009gfdvhp48majuk0hb7ragk7jqa0ephthkp8fgq0/rg03c1jvnehrrc617i0lnqjddc" 2025/03/13 01:30:39 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-vawaqoj2yalo/pre-dest1" 2025/03/13 01:30:39 DEBUG : Creating backend with remote "TestDrive:crypt/bi93ndoe3d0009gfdvhp48majuk0hb7ragk7jqa0ephthkp8fgq0/bbnblvh6k061ssopqrp18kd7gc" 2025/03/13 01:30:40 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-vawaqoj2yalo/pre-dest2" 2025/03/13 01:30:40 DEBUG : Creating backend with remote "TestDrive:crypt/bi93ndoe3d0009gfdvhp48majuk0hb7ragk7jqa0ephthkp8fgq0/dgicm1h6b5ejvlltm8eeif0bnk" 2025/03/13 01:30:41 DEBUG : 1: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/03/13 01:30:41 DEBUG : 1: Destination found in --compare-dest, skipping 2025/03/13 01:30:41 DEBUG : 2: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/03/13 01:30:41 DEBUG : 2: Destination found in --compare-dest, skipping 2025/03/13 01:30:42 DEBUG : 3: Need to transfer - File not found at Destination 2025/03/13 01:30:42 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vawaqoj2yalo/dest': Waiting for checks to finish 2025/03/13 01:30:42 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vawaqoj2yalo/dest': Waiting for transfers to finish 2025/03/13 01:30:44 DEBUG : 3: md5 = f88378bde8dd1aeeb24332f70ef35bc3 OK 2025/03/13 01:30:44 INFO : 3: Copied (new) 2025/03/13 01:30:44 DEBUG : Waiting for deletions to finish 2025/03/13 01:30:47 DEBUG : dgicm1h6b5ejvlltm8eeif0bnk: Rmdir: contains trashed file: "1ghu8geql9vrl726n32nrf65bc" 2025/03/13 01:30:48 DEBUG : bbnblvh6k061ssopqrp18kd7gc: Rmdir: contains trashed file: "skbfko3oil7es0lj68ob574sro" 2025/03/13 01:30:48 DEBUG : rg03c1jvnehrrc617i0lnqjddc: Rmdir: contains trashed file: "g072p7hmjchlnj0gibe64c1epg" --- PASS: TestSyncMultipleCompareDest (16.56s) === RUN TestSyncCopyDest run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-vawaqoj2yalo'", Local "Local file system at /tmp/rclone342727432", Modify Window "1ms" 2025/03/13 01:30:49 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-vawaqoj2yalo/dst" 2025/03/13 01:30:49 DEBUG : Creating backend with remote "TestDrive:crypt/bi93ndoe3d0009gfdvhp48majuk0hb7ragk7jqa0ephthkp8fgq0/31u3jie661vd5p8j7rtc3hgbh0" 2025/03/13 01:30:50 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-vawaqoj2yalo/CopyDest" 2025/03/13 01:30:51 DEBUG : Creating backend with remote "TestDrive:crypt/bi93ndoe3d0009gfdvhp48majuk0hb7ragk7jqa0ephthkp8fgq0/d09o6po3f7bm6ce32vdgs8h9ls" 2025/03/13 01:30:52 DEBUG : one: Need to transfer - File not found at Destination 2025/03/13 01:30:52 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vawaqoj2yalo/dst': Waiting for checks to finish 2025/03/13 01:30:52 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vawaqoj2yalo/dst': Waiting for transfers to finish 2025/03/13 01:30:55 DEBUG : one: md5 = 5c8d0c8523bf088b49b45de2167f322d OK 2025/03/13 01:30:55 INFO : one: Copied (new) 2025/03/13 01:30:55 DEBUG : Waiting for deletions to finish 2025/03/13 01:30:56 DEBUG : one: Sizes differ (src 5 vs dst 3) 2025/03/13 01:30:56 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vawaqoj2yalo/dst': Waiting for checks to finish 2025/03/13 01:30:56 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vawaqoj2yalo/dst': Waiting for transfers to finish 2025/03/13 01:30:58 DEBUG : one: md5 = fbce5bb80b2df59eeadf5843fc637363 OK 2025/03/13 01:30:58 INFO : one: Copied (replaced existing) 2025/03/13 01:30:58 DEBUG : Waiting for deletions to finish 2025/03/13 01:31:00 DEBUG : dst/one: md5 = e3e1485e4dfa2376c3dab68e7e93948d OK 2025/03/13 01:31:02 DEBUG : CopyDest/one: md5 = c1ab5146ddbca72189ff4f0ef0c974bc OK 2025/03/13 01:31:02 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-vawaqoj2yalo/BackupDir" 2025/03/13 01:31:02 DEBUG : Creating backend with remote "TestDrive:crypt/bi93ndoe3d0009gfdvhp48majuk0hb7ragk7jqa0ephthkp8fgq0/s6dbk3lfi7c9kfvo6j7bla9m0g" 2025/03/13 01:31:04 DEBUG : one: Sizes differ (src 5 vs dst 3) 2025/03/13 01:31:04 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vawaqoj2yalo/dst': Waiting for checks to finish 2025/03/13 01:31:05 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/03/13 01:31:05 DEBUG : one: Sizes differ (src 5 vs dst 3) 2025/03/13 01:31:06 INFO : one: Moved (server-side) 2025/03/13 01:31:07 INFO : one: Copied (server-side copy) 2025/03/13 01:31:07 DEBUG : one: Destination found in --copy-dest, using server-side copy 2025/03/13 01:31:07 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vawaqoj2yalo/dst': Waiting for transfers to finish 2025/03/13 01:31:07 DEBUG : Waiting for deletions to finish 2025/03/13 01:31:09 DEBUG : CopyDest/two: md5 = e6414ced23cd61cd7bfbfb804aee539d OK 2025/03/13 01:31:10 DEBUG : two: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/03/13 01:31:11 INFO : two: Copied (server-side copy) 2025/03/13 01:31:11 DEBUG : two: Destination found in --copy-dest, using server-side copy 2025/03/13 01:31:11 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/03/13 01:31:11 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vawaqoj2yalo/dst': Waiting for checks to finish 2025/03/13 01:31:11 DEBUG : one: Unchanged skipping 2025/03/13 01:31:11 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vawaqoj2yalo/dst': Waiting for transfers to finish 2025/03/13 01:31:11 DEBUG : Waiting for deletions to finish 2025/03/13 01:31:12 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/03/13 01:31:12 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vawaqoj2yalo/dst': Waiting for checks to finish 2025/03/13 01:31:12 DEBUG : one: Unchanged skipping 2025/03/13 01:31:12 DEBUG : two: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/03/13 01:31:12 DEBUG : two: Unchanged skipping 2025/03/13 01:31:12 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vawaqoj2yalo/dst': Waiting for transfers to finish 2025/03/13 01:31:12 DEBUG : Waiting for deletions to finish 2025/03/13 01:31:12 INFO : There was nothing to transfer 2025/03/13 01:31:14 DEBUG : CopyDest/three: md5 = fa314a50a139aa69153c957f0e68961f OK 2025/03/13 01:31:15 DEBUG : three: Sizes differ (src 7 vs dst 5) 2025/03/13 01:31:15 DEBUG : three: Destination not found in --copy-dest 2025/03/13 01:31:15 DEBUG : three: Need to transfer - File not found at Destination 2025/03/13 01:31:15 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/03/13 01:31:15 DEBUG : one: Unchanged skipping 2025/03/13 01:31:15 DEBUG : two: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/03/13 01:31:15 DEBUG : two: Unchanged skipping 2025/03/13 01:31:15 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vawaqoj2yalo/dst': Waiting for checks to finish 2025/03/13 01:31:15 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vawaqoj2yalo/dst': Waiting for transfers to finish 2025/03/13 01:31:16 DEBUG : three: md5 = 10c84250642f038f0447de8a071e16d4 OK 2025/03/13 01:31:16 INFO : three: Copied (new) 2025/03/13 01:31:16 DEBUG : Waiting for deletions to finish 2025/03/13 01:31:21 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "b6jdmn2b1adrhc8vikh7edr9os" 2025/03/13 01:31:21 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k" 2025/03/13 01:31:21 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" 2025/03/13 01:31:21 DEBUG : d09o6po3f7bm6ce32vdgs8h9ls: Rmdir: contains trashed file: "b6jdmn2b1adrhc8vikh7edr9os" 2025/03/13 01:31:21 DEBUG : d09o6po3f7bm6ce32vdgs8h9ls: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" 2025/03/13 01:31:21 DEBUG : d09o6po3f7bm6ce32vdgs8h9ls: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k" 2025/03/13 01:31:22 DEBUG : s6dbk3lfi7c9kfvo6j7bla9m0g: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" --- PASS: TestSyncCopyDest (33.89s) === RUN TestSyncBackupDir run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-vawaqoj2yalo'", Local "Local file system at /tmp/rclone342727432", Modify Window "1ms" 2025/03/13 01:31:25 DEBUG : dst/one: md5 = a7f3beaaf03851dfd1d0e8a599f9b317 OK 2025/03/13 01:31:26 DEBUG : dst/two: md5 = e95805e442d85470d003ef1ee26976b9 OK 2025/03/13 01:31:28 DEBUG : dst/three.txt: md5 = c07e04163f64351eae398de08e80528f OK 2025/03/13 01:31:28 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-vawaqoj2yalo/dst" 2025/03/13 01:31:28 DEBUG : Creating backend with remote "TestDrive:crypt/bi93ndoe3d0009gfdvhp48majuk0hb7ragk7jqa0ephthkp8fgq0/31u3jie661vd5p8j7rtc3hgbh0" 2025/03/13 01:31:29 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-vawaqoj2yalo/backup" 2025/03/13 01:31:29 DEBUG : Creating backend with remote "TestDrive:crypt/bi93ndoe3d0009gfdvhp48majuk0hb7ragk7jqa0ephthkp8fgq0/1nrff024r7pq65ecp72fc28jb0" 2025/03/13 01:31:31 DEBUG : one: Sizes differ (src 4 vs dst 3) 2025/03/13 01:31:31 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/03/13 01:31:31 DEBUG : two: Unchanged skipping 2025/03/13 01:31:31 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vawaqoj2yalo/dst': Waiting for checks to finish 2025/03/13 01:31:32 INFO : one: Moved (server-side) 2025/03/13 01:31:32 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vawaqoj2yalo/dst': Waiting for transfers to finish 2025/03/13 01:31:34 DEBUG : one: md5 = 8fa1fe319f80e51a4f7a742e016e5957 OK 2025/03/13 01:31:34 INFO : one: Copied (new) 2025/03/13 01:31:34 DEBUG : Waiting for deletions to finish 2025/03/13 01:31:35 INFO : three.txt: Moved (server-side) 2025/03/13 01:31:35 INFO : three.txt: Moved into backup dir 2025/03/13 01:31:36 DEBUG : dst/three.txt: md5 = 688753b06904bc11af3d41a594346ed0 OK 2025/03/13 01:31:37 DEBUG : one: Sizes differ (src 5 vs dst 4) 2025/03/13 01:31:37 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/03/13 01:31:37 DEBUG : two: Unchanged skipping 2025/03/13 01:31:37 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vawaqoj2yalo/dst': Waiting for checks to finish 2025/03/13 01:31:38 INFO : one: Deleted 2025/03/13 01:31:38 INFO : one: Moved (server-side) 2025/03/13 01:31:38 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vawaqoj2yalo/dst': Waiting for transfers to finish 2025/03/13 01:31:40 DEBUG : one: md5 = 4b4bbd39bdf43892f56cd616f1648b0b OK 2025/03/13 01:31:40 INFO : one: Copied (new) 2025/03/13 01:31:40 DEBUG : Waiting for deletions to finish 2025/03/13 01:31:41 INFO : three.txt: Deleted 2025/03/13 01:31:41 INFO : three.txt: Moved (server-side) 2025/03/13 01:31:41 INFO : three.txt: Moved into backup dir 2025/03/13 01:31:44 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" 2025/03/13 01:31:44 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k" 2025/03/13 01:31:45 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "tr2hj63d80ftlmvm6a952snjcc" 2025/03/13 01:31:45 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" 2025/03/13 01:31:45 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" 2025/03/13 01:31:45 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "tr2hj63d80ftlmvm6a952snjcc" --- PASS: TestSyncBackupDir (22.96s) === RUN TestSyncBackupDirWithSuffix run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-vawaqoj2yalo'", Local "Local file system at /tmp/rclone342727432", Modify Window "1ms" 2025/03/13 01:31:48 DEBUG : dst/one: md5 = 84cf8241ecfcc94816d25451f517d8fa OK 2025/03/13 01:31:49 DEBUG : dst/two: md5 = 4aa286a29be295a842c72622bf235418 OK 2025/03/13 01:31:51 DEBUG : dst/three.txt: md5 = 3e3d54fb95dc7d44fd89295fdab49ca6 OK 2025/03/13 01:31:51 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-vawaqoj2yalo/dst" 2025/03/13 01:31:51 DEBUG : Creating backend with remote "TestDrive:crypt/bi93ndoe3d0009gfdvhp48majuk0hb7ragk7jqa0ephthkp8fgq0/31u3jie661vd5p8j7rtc3hgbh0" 2025/03/13 01:31:52 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-vawaqoj2yalo/backup" 2025/03/13 01:31:52 DEBUG : Creating backend with remote "TestDrive:crypt/bi93ndoe3d0009gfdvhp48majuk0hb7ragk7jqa0ephthkp8fgq0/1nrff024r7pq65ecp72fc28jb0" 2025/03/13 01:31:54 DEBUG : one: Sizes differ (src 4 vs dst 3) 2025/03/13 01:31:54 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/03/13 01:31:54 DEBUG : two: Unchanged skipping 2025/03/13 01:31:54 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vawaqoj2yalo/dst': Waiting for checks to finish 2025/03/13 01:31:56 INFO : one: Moved (server-side) to: one.bak 2025/03/13 01:31:56 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vawaqoj2yalo/dst': Waiting for transfers to finish 2025/03/13 01:31:57 DEBUG : one: md5 = dcd6424d059ffbf37a15018d64387b33 OK 2025/03/13 01:31:57 INFO : one: Copied (new) 2025/03/13 01:31:57 DEBUG : Waiting for deletions to finish 2025/03/13 01:31:58 INFO : three.txt: Moved (server-side) to: three.txt.bak 2025/03/13 01:31:58 INFO : three.txt: Moved into backup dir 2025/03/13 01:31:59 DEBUG : dst/three.txt: md5 = 2800782f6c6d5beff77321b50e708f70 OK 2025/03/13 01:32:00 DEBUG : one: Sizes differ (src 5 vs dst 4) 2025/03/13 01:32:00 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/03/13 01:32:00 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vawaqoj2yalo/dst': Waiting for checks to finish 2025/03/13 01:32:00 DEBUG : two: Unchanged skipping 2025/03/13 01:32:01 INFO : one.bak: Deleted 2025/03/13 01:32:01 INFO : one: Moved (server-side) to: one.bak 2025/03/13 01:32:01 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vawaqoj2yalo/dst': Waiting for transfers to finish 2025/03/13 01:32:03 DEBUG : one: md5 = e998b7d9ca21fae9aef5f99b7c271f38 OK 2025/03/13 01:32:03 INFO : one: Copied (new) 2025/03/13 01:32:03 DEBUG : Waiting for deletions to finish 2025/03/13 01:32:03 INFO : three.txt.bak: Deleted 2025/03/13 01:32:04 INFO : three.txt: Moved (server-side) to: three.txt.bak 2025/03/13 01:32:04 INFO : three.txt: Moved into backup dir 2025/03/13 01:32:07 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" 2025/03/13 01:32:07 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k" 2025/03/13 01:32:08 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "qltcak2uaegtmcoa8vijdppbp8" 2025/03/13 01:32:08 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "sk91qgsqfn0r271r2ehsaoc20c" 2025/03/13 01:32:08 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "sk91qgsqfn0r271r2ehsaoc20c" 2025/03/13 01:32:08 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "qltcak2uaegtmcoa8vijdppbp8" --- PASS: TestSyncBackupDirWithSuffix (22.57s) === RUN TestSyncBackupDirWithSuffixKeepExtension run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-vawaqoj2yalo'", Local "Local file system at /tmp/rclone342727432", Modify Window "1ms" 2025/03/13 01:32:10 DEBUG : dst/one: md5 = 8ee4ce05a05a9cd320eb5675e5dd8e80 OK 2025/03/13 01:32:12 DEBUG : dst/two: md5 = c77ac64fdad030a4496a3ff4afcb0172 OK 2025/03/13 01:32:13 DEBUG : dst/three.txt: md5 = d0a7154820500238598579eae53ce54c OK 2025/03/13 01:32:14 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-vawaqoj2yalo/dst" 2025/03/13 01:32:14 DEBUG : Creating backend with remote "TestDrive:crypt/bi93ndoe3d0009gfdvhp48majuk0hb7ragk7jqa0ephthkp8fgq0/31u3jie661vd5p8j7rtc3hgbh0" 2025/03/13 01:32:15 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-vawaqoj2yalo/backup" 2025/03/13 01:32:15 DEBUG : Creating backend with remote "TestDrive:crypt/bi93ndoe3d0009gfdvhp48majuk0hb7ragk7jqa0ephthkp8fgq0/1nrff024r7pq65ecp72fc28jb0" 2025/03/13 01:32:16 DEBUG : one: Sizes differ (src 4 vs dst 3) 2025/03/13 01:32:16 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/03/13 01:32:16 DEBUG : two: Unchanged skipping 2025/03/13 01:32:16 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vawaqoj2yalo/dst': Waiting for checks to finish 2025/03/13 01:32:18 INFO : one: Moved (server-side) to: one-2019-01-01 2025/03/13 01:32:18 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vawaqoj2yalo/dst': Waiting for transfers to finish 2025/03/13 01:32:19 DEBUG : one: md5 = e8909f035f5731b10e37387c2dd7b5fb OK 2025/03/13 01:32:19 INFO : one: Copied (new) 2025/03/13 01:32:19 DEBUG : Waiting for deletions to finish 2025/03/13 01:32:20 INFO : three.txt: Moved (server-side) to: three-2019-01-01.txt 2025/03/13 01:32:20 INFO : three.txt: Moved into backup dir 2025/03/13 01:32:22 DEBUG : dst/three.txt: md5 = 4977d853a9a886c568e4d19c0b360bec OK 2025/03/13 01:32:23 DEBUG : one: Sizes differ (src 5 vs dst 4) 2025/03/13 01:32:23 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/03/13 01:32:23 DEBUG : two: Unchanged skipping 2025/03/13 01:32:23 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vawaqoj2yalo/dst': Waiting for checks to finish 2025/03/13 01:32:23 INFO : one-2019-01-01: Deleted 2025/03/13 01:32:24 INFO : one: Moved (server-side) to: one-2019-01-01 2025/03/13 01:32:24 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vawaqoj2yalo/dst': Waiting for transfers to finish 2025/03/13 01:32:25 DEBUG : one: md5 = 01cac9d5b2dab6b0da131cca82c5237c OK 2025/03/13 01:32:25 INFO : one: Copied (new) 2025/03/13 01:32:25 DEBUG : Waiting for deletions to finish 2025/03/13 01:32:26 INFO : three-2019-01-01.txt: Deleted 2025/03/13 01:32:27 INFO : three.txt: Moved (server-side) to: three-2019-01-01.txt 2025/03/13 01:32:27 INFO : three.txt: Moved into backup dir 2025/03/13 01:32:30 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" 2025/03/13 01:32:30 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k" 2025/03/13 01:32:30 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "jcjl1bv3ep0v8kt35lqql1co90" 2025/03/13 01:32:30 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "qtq2f6qq4lgpsmj88vb7147qje3prudmtfdtr2342fth58vo9a50" 2025/03/13 01:32:30 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "qtq2f6qq4lgpsmj88vb7147qje3prudmtfdtr2342fth58vo9a50" 2025/03/13 01:32:30 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "jcjl1bv3ep0v8kt35lqql1co90" --- PASS: TestSyncBackupDirWithSuffixKeepExtension (23.11s) === RUN TestSyncBackupDirSuffixOnly run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-vawaqoj2yalo'", Local "Local file system at /tmp/rclone342727432", Modify Window "1ms" 2025/03/13 01:32:33 DEBUG : dst/one: md5 = 1632ed951435dd6b1305814e2a62ecab OK 2025/03/13 01:32:35 DEBUG : dst/two: md5 = efb6e5d2d9e107cd2386f7bb44dbac57 OK 2025/03/13 01:32:36 DEBUG : dst/three.txt: md5 = f1b0772078606b1cacc008a2b367c823 OK 2025/03/13 01:32:37 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-vawaqoj2yalo/dst" 2025/03/13 01:32:37 DEBUG : Creating backend with remote "TestDrive:crypt/bi93ndoe3d0009gfdvhp48majuk0hb7ragk7jqa0ephthkp8fgq0/31u3jie661vd5p8j7rtc3hgbh0" 2025/03/13 01:32:38 DEBUG : one: Sizes differ (src 4 vs dst 3) 2025/03/13 01:32:38 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/03/13 01:32:38 DEBUG : two: Unchanged skipping 2025/03/13 01:32:38 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vawaqoj2yalo/dst': Waiting for checks to finish 2025/03/13 01:32:38 INFO : one: Moved (server-side) to: one.bak 2025/03/13 01:32:38 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vawaqoj2yalo/dst': Waiting for transfers to finish 2025/03/13 01:32:40 DEBUG : one: md5 = 82cc10330b57ecd11cec74c2d6978aec OK 2025/03/13 01:32:40 INFO : one: Copied (new) 2025/03/13 01:32:40 DEBUG : Waiting for deletions to finish 2025/03/13 01:32:41 INFO : three.txt: Moved (server-side) to: three.txt.bak 2025/03/13 01:32:41 INFO : three.txt: Moved into backup dir 2025/03/13 01:32:43 DEBUG : dst/three.txt: md5 = 0067e12e55ca206ab13f21c55373385b OK 2025/03/13 01:32:43 DEBUG : one.bak: Excluded (Path Filter) 2025/03/13 01:32:43 DEBUG : one.bak: Excluded 2025/03/13 01:32:43 DEBUG : three.txt.bak: Excluded (Path Filter) 2025/03/13 01:32:43 DEBUG : three.txt.bak: Excluded 2025/03/13 01:32:43 DEBUG : one: Sizes differ (src 5 vs dst 4) 2025/03/13 01:32:43 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/03/13 01:32:43 DEBUG : two: Unchanged skipping 2025/03/13 01:32:43 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vawaqoj2yalo/dst': Waiting for checks to finish 2025/03/13 01:32:44 INFO : one.bak: Deleted 2025/03/13 01:32:45 INFO : one: Moved (server-side) to: one.bak 2025/03/13 01:32:45 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vawaqoj2yalo/dst': Waiting for transfers to finish 2025/03/13 01:32:46 DEBUG : one: md5 = 715272ab766bace1ee2249b832a3f750 OK 2025/03/13 01:32:46 INFO : one: Copied (new) 2025/03/13 01:32:46 DEBUG : Waiting for deletions to finish 2025/03/13 01:32:47 INFO : three.txt.bak: Deleted 2025/03/13 01:32:47 INFO : three.txt: Moved (server-side) to: three.txt.bak 2025/03/13 01:32:47 INFO : three.txt: Moved into backup dir 2025/03/13 01:32:50 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" 2025/03/13 01:32:50 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "qltcak2uaegtmcoa8vijdppbp8" 2025/03/13 01:32:50 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "sk91qgsqfn0r271r2ehsaoc20c" 2025/03/13 01:32:50 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k" 2025/03/13 01:32:50 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "qltcak2uaegtmcoa8vijdppbp8" 2025/03/13 01:32:50 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "sk91qgsqfn0r271r2ehsaoc20c" --- PASS: TestSyncBackupDirSuffixOnly (19.27s) === RUN TestSyncSuffix run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-vawaqoj2yalo'", Local "Local file system at /tmp/rclone342727432", Modify Window "1ms" 2025/03/13 01:32:53 DEBUG : dst/one: md5 = f4419ac3f16925dc8e9d2cd73f0da6a0 OK 2025/03/13 01:32:54 DEBUG : dst/two: md5 = d878c1178f737a13a8ced1d4401097c3 OK 2025/03/13 01:32:56 DEBUG : dst/three.txt: md5 = 6f4cb6bd486c19b78c40ae74587558a0 OK 2025/03/13 01:32:56 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-vawaqoj2yalo/dst" 2025/03/13 01:32:56 DEBUG : Creating backend with remote "TestDrive:crypt/bi93ndoe3d0009gfdvhp48majuk0hb7ragk7jqa0ephthkp8fgq0/31u3jie661vd5p8j7rtc3hgbh0" 2025/03/13 01:32:57 DEBUG : one: Sizes differ (src 4 vs dst 3) 2025/03/13 01:32:58 INFO : one: Moved (server-side) to: one.bak 2025/03/13 01:32:59 DEBUG : one: md5 = 09cc92b35a295cca6f5737ea92a86a99 OK 2025/03/13 01:32:59 INFO : one: Copied (new) 2025/03/13 01:33:00 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/03/13 01:33:00 DEBUG : two: Unchanged skipping 2025/03/13 01:33:00 DEBUG : three.txt: Sizes differ (src 6 vs dst 5) 2025/03/13 01:33:01 INFO : three.txt: Moved (server-side) to: three.txt.bak 2025/03/13 01:33:02 DEBUG : three.txt: md5 = 12f3d123d3f407585c8863ebcd86c7d2 OK 2025/03/13 01:33:02 INFO : three.txt: Copied (new) 2025/03/13 01:33:03 DEBUG : one: Sizes differ (src 5 vs dst 4) 2025/03/13 01:33:04 INFO : one.bak: Deleted 2025/03/13 01:33:04 INFO : one: Moved (server-side) to: one.bak 2025/03/13 01:33:06 DEBUG : one: md5 = 04d843f27c42cf1b985135fdb593213b OK 2025/03/13 01:33:06 INFO : one: Copied (new) 2025/03/13 01:33:06 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/03/13 01:33:06 DEBUG : two: Unchanged skipping 2025/03/13 01:33:06 DEBUG : three.txt: Sizes differ (src 19 vs dst 6) 2025/03/13 01:33:07 INFO : three.txt.bak: Deleted 2025/03/13 01:33:08 INFO : three.txt: Moved (server-side) to: three.txt.bak 2025/03/13 01:33:09 DEBUG : three.txt: md5 = 322d1386c7b9e577fa062fbc51b5e6f6 OK 2025/03/13 01:33:09 INFO : three.txt: Copied (new) 2025/03/13 01:33:12 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" 2025/03/13 01:33:12 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "tr2hj63d80ftlmvm6a952snjcc" 2025/03/13 01:33:12 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "qltcak2uaegtmcoa8vijdppbp8" 2025/03/13 01:33:12 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "sk91qgsqfn0r271r2ehsaoc20c" 2025/03/13 01:33:12 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "sk91qgsqfn0r271r2ehsaoc20c" 2025/03/13 01:33:12 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k" 2025/03/13 01:33:12 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "qltcak2uaegtmcoa8vijdppbp8" --- PASS: TestSyncSuffix (22.56s) === RUN TestSyncSuffixKeepExtension run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-vawaqoj2yalo'", Local "Local file system at /tmp/rclone342727432", Modify Window "1ms" 2025/03/13 01:33:15 DEBUG : dst/one: md5 = 0352cc8ce8fb3ba4ed96cf167a7f9de1 OK 2025/03/13 01:33:17 DEBUG : dst/two: md5 = 7124fdbcfcea45a1b9b4cda855f2acd4 OK 2025/03/13 01:33:19 DEBUG : dst/three.txt: md5 = 0ae10756e2214f75b091f21de3378690 OK 2025/03/13 01:33:19 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-vawaqoj2yalo/dst" 2025/03/13 01:33:19 DEBUG : Creating backend with remote "TestDrive:crypt/bi93ndoe3d0009gfdvhp48majuk0hb7ragk7jqa0ephthkp8fgq0/31u3jie661vd5p8j7rtc3hgbh0" 2025/03/13 01:33:20 DEBUG : one: Sizes differ (src 4 vs dst 3) 2025/03/13 01:33:21 INFO : one: Moved (server-side) to: one-2019-01-01 2025/03/13 01:33:22 DEBUG : one: md5 = a810618d31cb4464c7f61dd8d7e4c1ed OK 2025/03/13 01:33:22 INFO : one: Copied (new) 2025/03/13 01:33:22 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/03/13 01:33:22 DEBUG : two: Unchanged skipping 2025/03/13 01:33:23 DEBUG : three.txt: Sizes differ (src 6 vs dst 5) 2025/03/13 01:33:23 INFO : three.txt: Moved (server-side) to: three-2019-01-01.txt 2025/03/13 01:33:25 DEBUG : three.txt: md5 = cb45c44c84f1f594bea8219683d001e5 OK 2025/03/13 01:33:25 INFO : three.txt: Copied (new) 2025/03/13 01:33:26 DEBUG : one: Sizes differ (src 5 vs dst 4) 2025/03/13 01:33:27 INFO : one-2019-01-01: Deleted 2025/03/13 01:33:27 INFO : one: Moved (server-side) to: one-2019-01-01 2025/03/13 01:33:29 DEBUG : one: md5 = cf19e62ca2caa5ddbfa5b974b1d347b7 OK 2025/03/13 01:33:29 INFO : one: Copied (new) 2025/03/13 01:33:29 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/03/13 01:33:29 DEBUG : two: Unchanged skipping 2025/03/13 01:33:29 DEBUG : three.txt: Sizes differ (src 19 vs dst 6) 2025/03/13 01:33:30 INFO : three-2019-01-01.txt: Deleted 2025/03/13 01:33:31 INFO : three.txt: Moved (server-side) to: three-2019-01-01.txt 2025/03/13 01:33:32 DEBUG : three.txt: md5 = fda52dff30b5e1a704bbe8b7206ab4e2 OK 2025/03/13 01:33:32 INFO : three.txt: Copied (new) 2025/03/13 01:33:36 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" 2025/03/13 01:33:36 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "tr2hj63d80ftlmvm6a952snjcc" 2025/03/13 01:33:36 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "jcjl1bv3ep0v8kt35lqql1co90" 2025/03/13 01:33:36 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k" 2025/03/13 01:33:36 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "jcjl1bv3ep0v8kt35lqql1co90" 2025/03/13 01:33:36 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "qtq2f6qq4lgpsmj88vb7147qje3prudmtfdtr2342fth58vo9a50" 2025/03/13 01:33:36 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "qtq2f6qq4lgpsmj88vb7147qje3prudmtfdtr2342fth58vo9a50" --- PASS: TestSyncSuffixKeepExtension (22.95s) === RUN TestSyncUTFNorm run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-vawaqoj2yalo'", Local "Local file system at /tmp/rclone342727432", Modify Window "1ms" 2025/03/13 01:33:37 DEBUG : Testêé: md5 = d2b4f42b1649d422efa923adaf2157f5 OK 2025/03/13 01:33:38 DEBUG : Testêé: Sizes differ (src 14 vs dst 18) 2025/03/13 01:33:38 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vawaqoj2yalo': Waiting for checks to finish 2025/03/13 01:33:38 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vawaqoj2yalo': Waiting for transfers to finish 2025/03/13 01:33:39 DEBUG : Testêé: md5 = fefd0416087aa144c8ab1a968ce01738 OK 2025/03/13 01:33:39 INFO : Testêé: Copied (replaced existing) to: Testêé 2025/03/13 01:33:39 DEBUG : Waiting for deletions to finish --- PASS: TestSyncUTFNorm (4.18s) === RUN TestSyncImmutable run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-vawaqoj2yalo'", Local "Local file system at /tmp/rclone342727432", Modify Window "1ms" 2025/03/13 01:33:41 DEBUG : existing: Need to transfer - File not found at Destination 2025/03/13 01:33:41 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vawaqoj2yalo': Waiting for checks to finish 2025/03/13 01:33:41 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vawaqoj2yalo': Waiting for transfers to finish 2025/03/13 01:33:42 DEBUG : existing: md5 = f7b1adb1d1fdc67760e90794647d07bd OK 2025/03/13 01:33:42 INFO : existing: Copied (new) 2025/03/13 01:33:42 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-vawaqoj2yalo'", Local "Local file system at /tmp/rclone342727432", Modify Window "1ms" 2025/03/13 01:33:43 DEBUG : existing: Sizes differ (src 8 vs dst 6) 2025/03/13 01:33:43 ERROR : existing: Source and destination exist but do not match: immutable file modified 2025/03/13 01:33:43 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vawaqoj2yalo': Waiting for checks to finish 2025/03/13 01:33:43 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vawaqoj2yalo': Waiting for transfers to finish 2025/03/13 01:33:43 ERROR : Encrypted drive 'TestCryptDrive:rclone-test-vawaqoj2yalo': not deleting files as there were IO errors 2025/03/13 01:33:43 ERROR : Encrypted drive 'TestCryptDrive:rclone-test-vawaqoj2yalo': not deleting directories as there were IO errors run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-vawaqoj2yalo'", Local "Local file system at /tmp/rclone342727432", Modify Window "1ms" --- PASS: TestSyncImmutable (4.94s) === RUN TestSyncIgnoreCase run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-vawaqoj2yalo'", Local "Local file system at /tmp/rclone342727432", Modify Window "1ms" 2025/03/13 01:33:47 DEBUG : EXISTING: md5 = 22ecb5e077227b09697e38a62145e7fc OK 2025/03/13 01:33:47 DEBUG : existing: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/03/13 01:33:47 DEBUG : existing: Unchanged skipping 2025/03/13 01:33:47 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vawaqoj2yalo': Waiting for checks to finish 2025/03/13 01:33:47 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vawaqoj2yalo': Waiting for transfers to finish 2025/03/13 01:33:47 DEBUG : Waiting for deletions to finish 2025/03/13 01:33:47 INFO : There was nothing to transfer --- PASS: TestSyncIgnoreCase (3.02s) === RUN TestFixCase run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-vawaqoj2yalo'", Local "Local file system at /tmp/rclone342727432", Modify Window "1ms" sync_test.go:2635: Skipping test as local or remote are case-sensitive --- SKIP: TestFixCase (0.49s) === RUN TestMaxTransfer === RUN TestMaxTransfer/Hard run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-vawaqoj2yalo'", Local "Local file system at /tmp/rclone342727432", 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-vawaqoj2yalo'", Local "Local file system at /tmp/rclone342727432", 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-vawaqoj2yalo'", Local "Local file system at /tmp/rclone342727432", Modify Window "1ms" sync_test.go:2674: This test only runs on local --- PASS: TestMaxTransfer (1.40s) --- SKIP: TestMaxTransfer/Hard (0.46s) --- SKIP: TestMaxTransfer/Soft (0.48s) --- SKIP: TestMaxTransfer/Cautious (0.45s) === RUN TestSyncConcurrentDelete run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-vawaqoj2yalo'", Local "Local file system at /tmp/rclone342727432", Modify Window "1ms" 2025/03/13 01:33:52 DEBUG : both0: md5 = c111c00b7a00be7f81c93ee0e4b685fe OK 2025/03/13 01:33:53 DEBUG : only0: md5 = 157c102a5f36045533c141415fca0f89 OK 2025/03/13 01:33:54 DEBUG : both1: md5 = 22fa2d92784da451535d0491ac700beb OK 2025/03/13 01:33:56 DEBUG : only1: md5 = 808d85863f5b90467b7ea8b5a3c76a94 OK 2025/03/13 01:33:57 DEBUG : both2: md5 = 9b7c97d197d71c887f46ea1c12b2ac4b OK 2025/03/13 01:33:59 DEBUG : only2: md5 = 3b9ffe3a4bd28864429aa49977cb04ec OK 2025/03/13 01:34:00 DEBUG : both3: md5 = 11355183e01d97b1c044889ff6afe1db OK 2025/03/13 01:34:02 DEBUG : only3: md5 = 58f87684d9c7dfb2cbe52615cf18855c OK 2025/03/13 01:34:03 DEBUG : both4: md5 = a279408cc853654a35c31bf27eba0efc OK 2025/03/13 01:34:04 DEBUG : only4: md5 = 9acea363a56bfcafa9389772bc650ab6 OK 2025/03/13 01:34:06 DEBUG : both5: md5 = 9675d47fce17151cfb07589d77f6d519 OK 2025/03/13 01:34:07 DEBUG : only5: md5 = d12fbe498c0b16da5bb183fbd06a57ca OK 2025/03/13 01:34:08 DEBUG : both6: md5 = 790bfb2dea2e471ecca2696985673915 OK 2025/03/13 01:34:10 DEBUG : only6: md5 = caa011564cdbaa66ce9cbb1d7e790b83 OK 2025/03/13 01:34:11 DEBUG : both7: md5 = c2580db237cb40229f98fa73a25b7959 OK 2025/03/13 01:34:13 DEBUG : only7: md5 = 0083cbb080ac512954e4729bf85835c9 OK 2025/03/13 01:34:14 DEBUG : both8: md5 = 8ed56ae32e6a4d56b9a4fb044a53c050 OK 2025/03/13 01:34:15 DEBUG : only8: md5 = 15ae1a3a0529c57fa6117040393da4dc OK 2025/03/13 01:34:17 DEBUG : both9: md5 = aed8c98ea728c560e3a9020396cd0d24 OK 2025/03/13 01:34:18 DEBUG : only9: md5 = d356842dea8214fc8fb6fb1d37c41be9 OK 2025/03/13 01:34:20 DEBUG : both10: md5 = 105aedece640feb61b383b74ff399a4c OK 2025/03/13 01:34:21 DEBUG : only10: md5 = cbfe11cd2415fe59ddb1a56bdff34136 OK 2025/03/13 01:34:22 DEBUG : both11: md5 = 9af969a73615a8e7ba43a75fbe7e210f OK 2025/03/13 01:34:24 DEBUG : only11: md5 = a6a7d87273a8e0d98b259caf58bd00d6 OK 2025/03/13 01:34:25 DEBUG : both12: md5 = 4b36a657668e7458defbb5fec33b4cba OK 2025/03/13 01:34:27 DEBUG : only12: md5 = c7ea259109e323f13dcd94339dcf704d OK 2025/03/13 01:34:28 DEBUG : both13: md5 = 05663af7745431940342828602b6d8df OK 2025/03/13 01:34:29 DEBUG : only13: md5 = 9254c134cc25dcec307a43e3241c0169 OK 2025/03/13 01:34:31 DEBUG : both14: md5 = bc1852003fa7725e9561e789b095794f OK 2025/03/13 01:34:32 DEBUG : only14: md5 = 52d8ce59496ca60a60d27ff468da4882 OK 2025/03/13 01:34:33 DEBUG : both15: md5 = 385a4a3489c918161fc4aac4638d7117 OK 2025/03/13 01:34:35 DEBUG : only15: md5 = 4c5c586b6cd886b75487fb3f0e3d1ae8 OK 2025/03/13 01:34:36 DEBUG : both16: md5 = 36b2efd113fe2792070960b01cd276b4 OK 2025/03/13 01:34:37 DEBUG : only16: md5 = 04844c3b044480165530696eea9be71a OK 2025/03/13 01:34:39 DEBUG : both17: md5 = b6637175804ef8306c9714a3a857ab61 OK 2025/03/13 01:34:40 DEBUG : only17: md5 = 0192fc25b0fff7328162285916ef15af OK 2025/03/13 01:34:42 DEBUG : both18: md5 = c66db2ba63520b9f2d1b7e48cc3af1e0 OK 2025/03/13 01:34:43 DEBUG : only18: md5 = 57fe6e38f9dba86ab70626b76067d753 OK 2025/03/13 01:34:45 DEBUG : both19: md5 = 23a5f6fd0ecb09cf3ff17a609fd3b4cb OK 2025/03/13 01:34:46 DEBUG : only19: md5 = dd623ea24d0b62e594b792eb872d4fd8 OK 2025/03/13 01:34:47 DEBUG : both0: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/03/13 01:34:47 DEBUG : both0: Unchanged skipping 2025/03/13 01:34:47 DEBUG : both1: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/03/13 01:34:47 DEBUG : both1: Unchanged skipping 2025/03/13 01:34:47 DEBUG : both10: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/03/13 01:34:47 DEBUG : both10: Unchanged skipping 2025/03/13 01:34:47 DEBUG : both11: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/03/13 01:34:47 DEBUG : both11: Unchanged skipping 2025/03/13 01:34:47 DEBUG : both12: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/03/13 01:34:47 DEBUG : both12: Unchanged skipping 2025/03/13 01:34:47 DEBUG : both13: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/03/13 01:34:47 DEBUG : both13: Unchanged skipping 2025/03/13 01:34:47 DEBUG : both14: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/03/13 01:34:47 DEBUG : both14: Unchanged skipping 2025/03/13 01:34:47 DEBUG : both15: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/03/13 01:34:47 DEBUG : both15: Unchanged skipping 2025/03/13 01:34:47 DEBUG : both16: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/03/13 01:34:47 DEBUG : both16: Unchanged skipping 2025/03/13 01:34:47 DEBUG : both17: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/03/13 01:34:47 DEBUG : both17: Unchanged skipping 2025/03/13 01:34:47 DEBUG : both18: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/03/13 01:34:47 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vawaqoj2yalo': Waiting for checks to finish 2025/03/13 01:34:47 DEBUG : both3: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/03/13 01:34:47 DEBUG : both3: Unchanged skipping 2025/03/13 01:34:47 DEBUG : both4: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/03/13 01:34:47 DEBUG : both4: Unchanged skipping 2025/03/13 01:34:47 DEBUG : both5: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/03/13 01:34:47 DEBUG : both5: Unchanged skipping 2025/03/13 01:34:47 DEBUG : both6: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/03/13 01:34:47 DEBUG : both6: Unchanged skipping 2025/03/13 01:34:47 DEBUG : both7: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/03/13 01:34:47 DEBUG : both7: Unchanged skipping 2025/03/13 01:34:47 DEBUG : both8: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/03/13 01:34:47 DEBUG : both8: Unchanged skipping 2025/03/13 01:34:47 DEBUG : both9: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/03/13 01:34:47 DEBUG : both9: Unchanged skipping 2025/03/13 01:34:47 DEBUG : both2: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/03/13 01:34:47 DEBUG : both19: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/03/13 01:34:47 DEBUG : both2: Unchanged skipping 2025/03/13 01:34:47 DEBUG : both19: Unchanged skipping 2025/03/13 01:34:47 DEBUG : both18: Unchanged skipping 2025/03/13 01:34:47 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vawaqoj2yalo': Waiting for transfers to finish 2025/03/13 01:34:47 DEBUG : Waiting for deletions to finish 2025/03/13 01:34:47 INFO : only11: Deleted 2025/03/13 01:34:47 INFO : only5: Deleted 2025/03/13 01:34:47 INFO : only14: Deleted 2025/03/13 01:34:47 INFO : only8: Deleted 2025/03/13 01:34:47 INFO : only9: Deleted 2025/03/13 01:34:47 INFO : only10: Deleted 2025/03/13 01:34:47 INFO : only0: Deleted 2025/03/13 01:34:47 INFO : only3: Deleted 2025/03/13 01:34:48 INFO : only13: Deleted 2025/03/13 01:34:48 INFO : only18: Deleted 2025/03/13 01:34:48 INFO : only12: Deleted 2025/03/13 01:34:48 INFO : only15: Deleted 2025/03/13 01:34:48 INFO : only2: Deleted 2025/03/13 01:34:48 INFO : only19: Deleted 2025/03/13 01:34:48 INFO : only6: Deleted 2025/03/13 01:34:48 INFO : only4: Deleted 2025/03/13 01:34:49 INFO : only1: Deleted 2025/03/13 01:34:49 INFO : only16: Deleted 2025/03/13 01:34:49 INFO : only7: Deleted 2025/03/13 01:34:49 INFO : only17: Deleted 2025/03/13 01:34:49 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-vawaqoj2yalo'", Local "Local file system at /tmp/rclone342727432", Modify Window "1ms" --- PASS: TestSyncConcurrentDelete (68.66s) === RUN TestSyncConcurrentTruncate run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-vawaqoj2yalo'", Local "Local file system at /tmp/rclone342727432", Modify Window "1ms" 2025/03/13 01:35:00 DEBUG : both0: md5 = e97297ba36fc8314931d4beb70309c27 OK 2025/03/13 01:35:02 DEBUG : only0: md5 = 5aec2d830f764cbda69a5d9b6b54b32b OK 2025/03/13 01:35:03 DEBUG : both1: md5 = a3c92fd81682f1bab4c2614923743222 OK 2025/03/13 01:35:05 DEBUG : only1: md5 = de271369ba737416dbc2438b8cde8046 OK 2025/03/13 01:35:06 DEBUG : both2: md5 = 0fa9679ab1169a59a613730fc65ebf78 OK 2025/03/13 01:35:08 DEBUG : only2: md5 = 29a1db18f560e257bb3422c6cc3784e6 OK 2025/03/13 01:35:09 DEBUG : both3: md5 = b2c822d471cd56365217224533e2e16c OK 2025/03/13 01:35:10 DEBUG : only3: md5 = e813eac07e37ba5df9e4c7e6297846bf OK 2025/03/13 01:35:12 DEBUG : both4: md5 = 5494458c4808da64791856c80d1ffca2 OK 2025/03/13 01:35:13 DEBUG : only4: md5 = 9c111ba6f4b0b3692e060a4420818eb0 OK 2025/03/13 01:35:14 DEBUG : both5: md5 = 96f961de800a7333da938baaead6d1f5 OK 2025/03/13 01:35:16 DEBUG : only5: md5 = e83b4d48c5aeb68edbb77d851ffb2f5c OK 2025/03/13 01:35:17 DEBUG : both6: md5 = f97d96c69c2899e7727e14b50ce13c37 OK 2025/03/13 01:35:18 DEBUG : only6: md5 = c6f7538362981474abefce8ad4029bbc OK 2025/03/13 01:35:20 DEBUG : both7: md5 = 99b49c03b6ba641a57c2b0e15986358d OK 2025/03/13 01:35:21 DEBUG : only7: md5 = 700098d7c3218ede5c163fb1b3343c67 OK 2025/03/13 01:35:23 DEBUG : both8: md5 = 1af58d14cfcafdf283e8f854e64baf88 OK 2025/03/13 01:35:24 DEBUG : only8: md5 = 51b8f4ce09b0ab8b89036b6242c7a04a OK 2025/03/13 01:35:26 DEBUG : both9: md5 = 474c7aa97797d53b5e8c990303182ee5 OK 2025/03/13 01:35:27 DEBUG : only9: md5 = cb5e0d56c618fc845a28c67267e20b04 OK 2025/03/13 01:35:28 DEBUG : both10: md5 = 7d1eda15349547f0880363e2e26ec6d8 OK 2025/03/13 01:35:30 DEBUG : only10: md5 = 5b1ff1a80f143563a55c3dc59018babe OK 2025/03/13 01:35:31 DEBUG : both11: md5 = 74b9ae420228daa29485aa4a358db033 OK 2025/03/13 01:35:33 DEBUG : only11: md5 = 233633574519b996a2cbf42101612a40 OK 2025/03/13 01:35:34 DEBUG : both12: md5 = e2238c81665775027e444869b99a9e21 OK 2025/03/13 01:35:35 DEBUG : only12: md5 = 8e5e171df8515e8bd796b216c94d347d OK 2025/03/13 01:35:37 DEBUG : both13: md5 = 194cf0609642e8173adbe0faad63a4e3 OK 2025/03/13 01:35:38 DEBUG : only13: md5 = 0b11f9751196dfad1cb83ed5b1d67e62 OK 2025/03/13 01:35:40 DEBUG : both14: md5 = 94bd062e0de5c786d9d01f287b591ce5 OK 2025/03/13 01:35:41 DEBUG : only14: md5 = fa691b2fa0c2969c23768852780574b6 OK 2025/03/13 01:35:42 DEBUG : both15: md5 = 3a87b87aaab09686b8de1d957ed8ccdc OK 2025/03/13 01:35:44 DEBUG : only15: md5 = 1296f512e9455e867a266d2e9d6f9101 OK 2025/03/13 01:35:45 DEBUG : both16: md5 = 629f4a3a4c01cdf9b0060c442e0641d8 OK 2025/03/13 01:35:47 DEBUG : only16: md5 = c2dc77688b96eb6a5549132edd870772 OK 2025/03/13 01:35:48 DEBUG : both17: md5 = 086027e0f9af66b62b03b058a22b5850 OK 2025/03/13 01:35:50 DEBUG : only17: md5 = a5453eff7fb12a651001ccfd9d8f19ca OK 2025/03/13 01:35:51 DEBUG : both18: md5 = 380ea484432fa55577e34bb545b35a84 OK 2025/03/13 01:35:52 DEBUG : only18: md5 = 880051948c96f6785f9fe14822cacba2 OK 2025/03/13 01:35:54 DEBUG : both19: md5 = 63d2372b1c238c1abd2b427383043b7b OK 2025/03/13 01:35:55 DEBUG : only19: md5 = d00668f006fd115152e5558708aa8d46 OK 2025/03/13 01:35:56 DEBUG : both0: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/03/13 01:35:56 DEBUG : both1: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/03/13 01:35:56 DEBUG : both10: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/03/13 01:35:56 DEBUG : both11: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/03/13 01:35:56 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vawaqoj2yalo': Waiting for checks to finish 2025/03/13 01:35:56 DEBUG : both0: Unchanged skipping 2025/03/13 01:35:56 DEBUG : both12: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/03/13 01:35:56 DEBUG : both1: Unchanged skipping 2025/03/13 01:35:56 DEBUG : both13: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/03/13 01:35:56 DEBUG : both12: Unchanged skipping 2025/03/13 01:35:56 DEBUG : both14: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/03/13 01:35:56 DEBUG : both14: Unchanged skipping 2025/03/13 01:35:56 DEBUG : both15: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/03/13 01:35:56 DEBUG : both15: Unchanged skipping 2025/03/13 01:35:56 DEBUG : both16: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/03/13 01:35:56 DEBUG : both16: Unchanged skipping 2025/03/13 01:35:56 DEBUG : both17: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/03/13 01:35:56 DEBUG : both17: Unchanged skipping 2025/03/13 01:35:56 DEBUG : both18: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/03/13 01:35:56 DEBUG : both18: Unchanged skipping 2025/03/13 01:35:56 DEBUG : both19: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/03/13 01:35:56 DEBUG : both19: Unchanged skipping 2025/03/13 01:35:56 DEBUG : both2: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/03/13 01:35:56 DEBUG : both2: Unchanged skipping 2025/03/13 01:35:56 DEBUG : both3: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/03/13 01:35:56 DEBUG : both3: Unchanged skipping 2025/03/13 01:35:56 DEBUG : both4: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/03/13 01:35:56 DEBUG : both13: Unchanged skipping 2025/03/13 01:35:56 DEBUG : both5: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/03/13 01:35:56 DEBUG : both11: Unchanged skipping 2025/03/13 01:35:56 DEBUG : both6: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/03/13 01:35:56 DEBUG : both10: Unchanged skipping 2025/03/13 01:35:56 DEBUG : both7: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/03/13 01:35:56 DEBUG : both4: Unchanged skipping 2025/03/13 01:35:56 DEBUG : both5: Unchanged skipping 2025/03/13 01:35:56 DEBUG : both8: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/03/13 01:35:56 DEBUG : both9: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/03/13 01:35:56 DEBUG : both8: Unchanged skipping 2025/03/13 01:35:56 DEBUG : only0: Sizes differ (src 0 vs dst 6) 2025/03/13 01:35:56 DEBUG : only1: Sizes differ (src 0 vs dst 6) 2025/03/13 01:35:56 DEBUG : only10: Sizes differ (src 0 vs dst 6) 2025/03/13 01:35:56 DEBUG : both9: Unchanged skipping 2025/03/13 01:35:56 DEBUG : only11: Sizes differ (src 0 vs dst 6) 2025/03/13 01:35:56 DEBUG : only12: Sizes differ (src 0 vs dst 6) 2025/03/13 01:35:56 DEBUG : both7: Unchanged skipping 2025/03/13 01:35:56 DEBUG : only14: Sizes differ (src 0 vs dst 6) 2025/03/13 01:35:56 DEBUG : only13: Sizes differ (src 0 vs dst 6) 2025/03/13 01:35:56 DEBUG : only15: Sizes differ (src 0 vs dst 6) 2025/03/13 01:35:56 DEBUG : only16: Sizes differ (src 0 vs dst 6) 2025/03/13 01:35:56 DEBUG : only17: Sizes differ (src 0 vs dst 6) 2025/03/13 01:35:56 DEBUG : only18: Sizes differ (src 0 vs dst 6) 2025/03/13 01:35:56 DEBUG : only19: Sizes differ (src 0 vs dst 6) 2025/03/13 01:35:56 DEBUG : only2: Sizes differ (src 0 vs dst 6) 2025/03/13 01:35:56 DEBUG : only3: Sizes differ (src 0 vs dst 6) 2025/03/13 01:35:56 DEBUG : only4: Sizes differ (src 0 vs dst 6) 2025/03/13 01:35:56 DEBUG : only5: Sizes differ (src 0 vs dst 6) 2025/03/13 01:35:56 DEBUG : only6: Sizes differ (src 0 vs dst 6) 2025/03/13 01:35:56 DEBUG : only7: Sizes differ (src 0 vs dst 6) 2025/03/13 01:35:56 DEBUG : both6: Unchanged skipping 2025/03/13 01:35:56 DEBUG : only8: Sizes differ (src 0 vs dst 6) 2025/03/13 01:35:56 DEBUG : only9: Sizes differ (src 0 vs dst 6) 2025/03/13 01:35:56 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vawaqoj2yalo': Waiting for transfers to finish 2025/03/13 01:35:57 DEBUG : only1: md5 = 2b06d9ec3617243f27cd81ed156647d9 OK 2025/03/13 01:35:57 INFO : only1: Copied (replaced existing) 2025/03/13 01:35:57 DEBUG : only12: md5 = cc7984b4c5cf748721f089eeca98df05 OK 2025/03/13 01:35:57 INFO : only12: Copied (replaced existing) 2025/03/13 01:35:57 DEBUG : only0: md5 = b259e54619c9b4765af90a86687ae131 OK 2025/03/13 01:35:57 INFO : only0: Copied (replaced existing) 2025/03/13 01:35:57 DEBUG : only11: md5 = 58fef7ee5e4406d48143cea9420a455e OK 2025/03/13 01:35:57 INFO : only11: Copied (replaced existing) 2025/03/13 01:35:58 DEBUG : only14: md5 = c3ccc775b91f960b7dd5c1ab5c104abf OK 2025/03/13 01:35:58 INFO : only14: Copied (replaced existing) 2025/03/13 01:35:58 DEBUG : only13: md5 = 0e7bb4e8a4629e33474067e8919683dd OK 2025/03/13 01:35:58 INFO : only13: Copied (replaced existing) 2025/03/13 01:35:58 DEBUG : only16: md5 = 76a4b1a2adc3646f6a6f9b03e5244d03 OK 2025/03/13 01:35:58 INFO : only16: Copied (replaced existing) 2025/03/13 01:35:58 DEBUG : only17: md5 = 0659c8368f28ebe8d1ec930762bbb658 OK 2025/03/13 01:35:58 INFO : only17: Copied (replaced existing) 2025/03/13 01:35:59 DEBUG : only18: md5 = eba4208bd26a151bad3ad590e196e6df OK 2025/03/13 01:35:59 INFO : only18: Copied (replaced existing) 2025/03/13 01:35:59 DEBUG : only19: md5 = d8a48e868b63a9185a0a95aab5e91276 OK 2025/03/13 01:35:59 INFO : only19: Copied (replaced existing) 2025/03/13 01:36:00 DEBUG : only3: md5 = 43a05e6c30d7abde40af705531737bbf OK 2025/03/13 01:36:00 INFO : only3: Copied (replaced existing) 2025/03/13 01:36:00 DEBUG : only2: md5 = 6a2f419133d954c5c55bef5a22bbb914 OK 2025/03/13 01:36:00 INFO : only2: Copied (replaced existing) 2025/03/13 01:36:00 DEBUG : only4: md5 = bb7967774cec297077c7c2c816ff86a5 OK 2025/03/13 01:36:00 INFO : only4: Copied (replaced existing) 2025/03/13 01:36:00 DEBUG : only15: md5 = 27e3d0eed4b3d499abc5070c8aeebeee OK 2025/03/13 01:36:00 INFO : only15: Copied (replaced existing) 2025/03/13 01:36:01 DEBUG : only6: md5 = e7df42718f14afdc9a7422416dadf192 OK 2025/03/13 01:36:01 INFO : only6: Copied (replaced existing) 2025/03/13 01:36:01 DEBUG : only7: md5 = decf2a9d29ef25eb5218a66e5fa89122 OK 2025/03/13 01:36:01 INFO : only7: Copied (replaced existing) 2025/03/13 01:36:02 DEBUG : only5: md5 = f2e5493ee9f7d09fca2af5c354e1b269 OK 2025/03/13 01:36:02 INFO : only5: Copied (replaced existing) 2025/03/13 01:36:02 DEBUG : only8: md5 = d3c7107633becd5ddfb80f4321355bbd OK 2025/03/13 01:36:02 INFO : only8: Copied (replaced existing) 2025/03/13 01:36:02 DEBUG : only9: md5 = e3b7ee27109a6f3ec37eca58c4d717d2 OK 2025/03/13 01:36:02 INFO : only9: Copied (replaced existing) 2025/03/13 01:36:02 DEBUG : only10: md5 = 050750267776245d6407f2722b47e0f7 OK 2025/03/13 01:36:02 INFO : only10: Copied (replaced existing) 2025/03/13 01:36:02 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-vawaqoj2yalo'", Local "Local file system at /tmp/rclone342727432", Modify Window "1ms" --- PASS: TestSyncConcurrentTruncate (82.01s) === RUN TestSyncReplaceDirModTime run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-vawaqoj2yalo'", Local "Local file system at /tmp/rclone342727432", Modify Window "1ms" 2025/03/13 01:36:21 DEBUG : empty_dir: Making directory with metadata 2025/03/13 01:36:21 INFO : empty_dir: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2025/03/13 01:36:21 DEBUG : empty_on_remote: Making directory with metadata 2025/03/13 01:36:21 INFO : empty_on_remote: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2025/03/13 01:36:21 DEBUG : empty_on_remote: Making directory with metadata 2025/03/13 01:36:22 INFO : empty_on_remote: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-vawaqoj2yalo'", Local "Local file system at /tmp/rclone342727432", Modify Window "1ms" 2025/03/13 01:36:27 INFO : test_dir1: Set directory modification time (using DirSetModTime) 2025/03/13 01:36:27 INFO : test_dir2: Set directory modification time (using DirSetModTime) 2025/03/13 01:36:27 INFO : test_dir2/sub_dir: Set directory modification time (using DirSetModTime) 2025/03/13 01:36:27 INFO : empty_on_remote: Set directory modification time (using DirSetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-vawaqoj2yalo'", Local "Local file system at /tmp/rclone342727432", Modify Window "1ms" 2025/03/13 01:36:33 DEBUG : heqj02jg0dcqlem7gl0500bvp0/24g2k8bseitblkmqnie1ibl2s8: Rmdir: contains trashed file: "633fmaa0qic3kv3cladnu11pto" 2025/03/13 01:36:34 DEBUG : heqj02jg0dcqlem7gl0500bvp0: Rmdir: contains trashed file: "24g2k8bseitblkmqnie1ibl2s8" 2025/03/13 01:36:35 DEBUG : gq68srrpl0nnf394bgf7dbu9kc: Rmdir: contains trashed file: "d26uovf0miqhd1mu3c9jbseq00" --- PASS: TestSyncReplaceDirModTime (16.07s) === RUN TestSyncReplaceDirModTimeWithEmptyDirs run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-vawaqoj2yalo'", Local "Local file system at /tmp/rclone342727432", Modify Window "1ms" 2025/03/13 01:36:37 DEBUG : empty_dir: Making directory with metadata 2025/03/13 01:36:37 INFO : empty_dir: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2025/03/13 01:36:37 DEBUG : empty_on_remote: Making directory with metadata 2025/03/13 01:36:37 INFO : empty_on_remote: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2025/03/13 01:36:37 DEBUG : empty_on_remote: Making directory with metadata 2025/03/13 01:36:38 INFO : empty_on_remote: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-vawaqoj2yalo'", Local "Local file system at /tmp/rclone342727432", Modify Window "1ms" 2025/03/13 01:36:42 INFO : test_dir1: Set directory modification time (using DirSetModTime) 2025/03/13 01:36:42 INFO : test_dir2: Set directory modification time (using DirSetModTime) 2025/03/13 01:36:42 INFO : test_dir2/sub_dir: Set directory modification time (using DirSetModTime) 2025/03/13 01:36:42 INFO : empty_on_remote: Set directory modification time (using DirSetModTime) 2025/03/13 01:36:42 INFO : empty_dir: Set directory modification time (using DirSetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-vawaqoj2yalo'", Local "Local file system at /tmp/rclone342727432", Modify Window "1ms" 2025/03/13 01:36:50 DEBUG : heqj02jg0dcqlem7gl0500bvp0/24g2k8bseitblkmqnie1ibl2s8: Rmdir: contains trashed file: "633fmaa0qic3kv3cladnu11pto" 2025/03/13 01:36:50 DEBUG : heqj02jg0dcqlem7gl0500bvp0: Rmdir: contains trashed file: "24g2k8bseitblkmqnie1ibl2s8" 2025/03/13 01:36:51 DEBUG : gq68srrpl0nnf394bgf7dbu9kc: Rmdir: contains trashed file: "d26uovf0miqhd1mu3c9jbseq00" --- PASS: TestSyncReplaceDirModTimeWithEmptyDirs (17.00s) === RUN TestNothingToTransferWithEmptyDirs run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-vawaqoj2yalo'", Local "Local file system at /tmp/rclone342727432", Modify Window "1ms" 2025/03/13 01:36:54 INFO : sub dir: Set directory modification time (using DirSetModTime) 2025/03/13 01:36:54 DEBUG : sub dir: Making directory with metadata 2025/03/13 01:36:55 INFO : sub dir: Made directory with metadata (mtime=2011-12-30T12:59:59Z) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-vawaqoj2yalo'", Local "Local file system at /tmp/rclone342727432", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-vawaqoj2yalo'", Local "Local file system at /tmp/rclone342727432", Modify Window "1ms" 2025/03/13 01:37:13 INFO : sub dir2: Set directory modification time (using DirSetModTime) 2025/03/13 01:37:13 INFO : sub dir2: Set directory modification time (using DirSetModTime) 2025/03/13 01:37:13 INFO : sub dirEmpty/sub dirEmpty2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2025/03/13 01:37:13 INFO : sub dirEmpty: Set directory modification time (using DirSetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-vawaqoj2yalo'", Local "Local file system at /tmp/rclone342727432", Modify Window "1ms" 2025/03/13 01:37:26 DEBUG : gcsdkq814sbtppue42dpsbg8ug: Rmdir: contains trashed file: "sjuo65gk5q3r1199jselk9k9o0" 2025/03/13 01:37:26 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/37qp6d1gohacv723ij3brofbu8/i24n0ln37pa2hv8pctddeuh73o: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" 2025/03/13 01:37:27 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/37qp6d1gohacv723ij3brofbu8: Rmdir: contains trashed file: "i24n0ln37pa2hv8pctddeuh73o" 2025/03/13 01:37:28 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "37qp6d1gohacv723ij3brofbu8" 2025/03/13 01:37:28 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak" 2025/03/13 01:37:29 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak" 2025/03/13 01:37:30 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak" 2025/03/13 01:37:31 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak" 2025/03/13 01:37:31 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/4r13oncfa2rsrr82oqhsqv24ns: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" 2025/03/13 01:37:32 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc: Rmdir: contains trashed file: "4r13oncfa2rsrr82oqhsqv24ns" 2025/03/13 01:37:32 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak" 2025/03/13 01:37:33 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestNothingToTransferWithEmptyDirs (41.04s) === RUN TestNothingToTransferWithoutEmptyDirs run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-vawaqoj2yalo'", Local "Local file system at /tmp/rclone342727432", Modify Window "1ms" 2025/03/13 01:37:35 INFO : sub dir: Set directory modification time (using DirSetModTime) 2025/03/13 01:37:35 DEBUG : sub dir: Making directory with metadata 2025/03/13 01:37:36 INFO : sub dir: Made directory with metadata (mtime=2011-12-30T12:59:59Z) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-vawaqoj2yalo'", Local "Local file system at /tmp/rclone342727432", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-vawaqoj2yalo'", Local "Local file system at /tmp/rclone342727432", Modify Window "1ms" 2025/03/13 01:37:58 INFO : sub dir2: Set directory modification time (using DirSetModTime) 2025/03/13 01:37:59 INFO : sub dir2: Set directory modification time (using DirSetModTime) 2025/03/13 01:37:59 INFO : sub dirEmpty/sub dirEmpty2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2025/03/13 01:37:59 INFO : sub dirEmpty: Set directory modification time (using DirSetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-vawaqoj2yalo'", Local "Local file system at /tmp/rclone342727432", Modify Window "1ms" 2025/03/13 01:38:11 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/37qp6d1gohacv723ij3brofbu8/i24n0ln37pa2hv8pctddeuh73o: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" 2025/03/13 01:38:11 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/37qp6d1gohacv723ij3brofbu8: Rmdir: contains trashed file: "i24n0ln37pa2hv8pctddeuh73o" 2025/03/13 01:38:12 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "37qp6d1gohacv723ij3brofbu8" 2025/03/13 01:38:13 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak" 2025/03/13 01:38:13 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak" 2025/03/13 01:38:14 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak" 2025/03/13 01:38:15 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak" 2025/03/13 01:38:16 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/4r13oncfa2rsrr82oqhsqv24ns: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" 2025/03/13 01:38:16 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc: Rmdir: contains trashed file: "4r13oncfa2rsrr82oqhsqv24ns" 2025/03/13 01:38:16 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak" 2025/03/13 01:38:17 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestNothingToTransferWithoutEmptyDirs (43.97s) PASS 2025/03/13 01:38:19 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vawaqoj2yalo': Purge remote "./sync.test -test.v -test.timeout 1h0m0s -remote TestCryptDrive: -verbose" - Finished OK in 16m25.6418688s (try 1/5)