"./sync.test -test.v -test.timeout 1h0m0s -remote TestCryptDrive: -verbose -fast-list" - Starting (try 1/5) 2025/04/19 01:50:52 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-feyixep3capu" 2025/04/19 01:50:52 DEBUG : Using config file from "/home/rclone/.rclone.conf" 2025/04/19 01:50:52 DEBUG : Creating backend with remote "TestDrive:crypt/iktac5oqe17khgjvgdp5oj3naolfecsltrdlansb2vpgjtapv0j0" 2025/04/19 01:50:53 DEBUG : Creating backend with remote "/tmp/rclone3509792376" === RUN TestPipe --- PASS: TestPipe (0.00s) === RUN TestPipeConcurrent --- PASS: TestPipeConcurrent (0.04s) === RUN TestPipeOrderBy === RUN TestPipeOrderBy/#00 === RUN TestPipeOrderBy/size === RUN TestPipeOrderBy/name === RUN TestPipeOrderBy/modtime === RUN TestPipeOrderBy/size,ascending === RUN TestPipeOrderBy/name,asc === RUN TestPipeOrderBy/modtime,ascending === RUN TestPipeOrderBy/size,descending === RUN TestPipeOrderBy/name,desc === RUN TestPipeOrderBy/modtime,descending === RUN TestPipeOrderBy/size,mixed,50 === RUN TestPipeOrderBy/size,mixed,51 --- PASS: TestPipeOrderBy (0.00s) --- PASS: TestPipeOrderBy/#00 (0.00s) --- PASS: TestPipeOrderBy/size (0.00s) --- PASS: TestPipeOrderBy/name (0.00s) --- PASS: TestPipeOrderBy/modtime (0.00s) --- PASS: TestPipeOrderBy/size,ascending (0.00s) --- PASS: TestPipeOrderBy/name,asc (0.00s) --- PASS: TestPipeOrderBy/modtime,ascending (0.00s) --- PASS: TestPipeOrderBy/size,descending (0.00s) --- PASS: TestPipeOrderBy/name,desc (0.00s) --- PASS: TestPipeOrderBy/modtime,descending (0.00s) --- PASS: TestPipeOrderBy/size,mixed,50 (0.00s) --- PASS: TestPipeOrderBy/size,mixed,51 (0.00s) === RUN TestNewLess === RUN TestNewLess/blankOK === RUN TestNewLess/tooManyParts === RUN TestNewLess/tooManyParts2 === RUN TestNewLess/badMixed === RUN TestNewLess/unknownComparison === RUN TestNewLess/unknownSortDirection === RUN TestNewLess/size === RUN TestNewLess/name === RUN TestNewLess/modtime === RUN TestNewLess/size,ascending === RUN TestNewLess/name,asc === RUN TestNewLess/modtime,ascending === RUN TestNewLess/size,descending === RUN TestNewLess/name,desc === RUN TestNewLess/modtime,descending === RUN TestNewLess/modtime,mixed === RUN TestNewLess/modtime,mixed,30 --- PASS: TestNewLess (0.00s) --- PASS: TestNewLess/blankOK (0.00s) --- PASS: TestNewLess/tooManyParts (0.00s) --- PASS: TestNewLess/tooManyParts2 (0.00s) --- PASS: TestNewLess/badMixed (0.00s) --- PASS: TestNewLess/unknownComparison (0.00s) --- PASS: TestNewLess/unknownSortDirection (0.00s) --- PASS: TestNewLess/size (0.00s) --- PASS: TestNewLess/name (0.00s) --- PASS: TestNewLess/modtime (0.00s) --- PASS: TestNewLess/size,ascending (0.00s) --- PASS: TestNewLess/name,asc (0.00s) --- PASS: TestNewLess/modtime,ascending (0.00s) --- PASS: TestNewLess/size,descending (0.00s) --- PASS: TestNewLess/name,desc (0.00s) --- PASS: TestNewLess/modtime,descending (0.00s) --- PASS: TestNewLess/modtime,mixed (0.00s) --- PASS: TestNewLess/modtime,mixed,30 (0.00s) === RUN TestRcCopy rc_test.go:16: Skipping test on non local remote --- SKIP: TestRcCopy (0.00s) === RUN TestRcMove rc_test.go:16: Skipping test on non local remote --- SKIP: TestRcMove (0.00s) === RUN TestRcSync rc_test.go:16: Skipping test on non local remote --- SKIP: TestRcSync (0.00s) === RUN TestCopyWithDryRun run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-feyixep3capu'", Local "Local file system at /tmp/rclone3509792376", Modify Window "1ms" 2025/04/19 01:50:54 DEBUG : Added delayed dir = "sub dir", newDst= 2025/04/19 01:50:54 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2025/04/19 01:50:54 NOTICE: sub dir/hello world: Skipped copy as --dry-run is set (size 11) 2025/04/19 01:50:54 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-feyixep3capu': Waiting for checks to finish 2025/04/19 01:50:54 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-feyixep3capu': Waiting for transfers to finish 2025/04/19 01:50:54 NOTICE: sub dir: Skipped set directory modification time as --dry-run is set run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-feyixep3capu'", Local "Local file system at /tmp/rclone3509792376", Modify Window "1ms" --- PASS: TestCopyWithDryRun (1.97s) === RUN TestCopy run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-feyixep3capu'", Local "Local file system at /tmp/rclone3509792376", Modify Window "1ms" 2025/04/19 01:50:55 INFO : sub dir: Set directory modification time (using DirSetModTime) 2025/04/19 01:50:56 DEBUG : Added delayed dir = "sub dir", newDst= 2025/04/19 01:50:56 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2025/04/19 01:50:56 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-feyixep3capu': Waiting for checks to finish 2025/04/19 01:50:56 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-feyixep3capu': Waiting for transfers to finish 2025/04/19 01:50:58 DEBUG : sub dir/hello world: md5 = 1a65e73c1d05d6bb163b1c8eb7330fa7 OK 2025/04/19 01:50:58 INFO : sub dir/hello world: Copied (new) 2025/04/19 01:50:58 INFO : sub dir: Set directory modification time (using DirSetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-feyixep3capu'", Local "Local file system at /tmp/rclone3509792376", Modify Window "1ms" 2025/04/19 01:51:00 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestCopy (5.77s) === RUN TestCopyMetadata run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-feyixep3capu'", Local "Local file system at /tmp/rclone3509792376", Modify Window "1ms" 2025/04/19 01:51:01 DEBUG : metadata sub dir: Making directory with metadata 2025/04/19 01:51:01 INFO : metadata sub dir: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2025/04/19 01:51:01 DEBUG : empty metadata sub dir: Making directory with metadata 2025/04/19 01:51:01 INFO : empty metadata sub dir: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2025/04/19 01:51:01 DEBUG : Local file system at /tmp/rclone3509792376: File to upload is small (21 bytes), uploading instead of streaming 2025/04/19 01:51:01 DEBUG : metadata sub dir/hello metadata world: md5 = baa7a013449dbba2b1ed02b5cfb4e1a2 OK 2025/04/19 01:51:01 DEBUG : metadata sub dir/hello metadata world: Size and md5 of src and dst objects identical 2025/04/19 01:51:01 INFO : metadata sub dir: Set directory modification time (using DirSetModTime) 2025/04/19 01:51:02 DEBUG : Google drive root 'crypt/iktac5oqe17khgjvgdp5oj3naolfecsltrdlansb2vpgjtapv0j0': Skipping btime metadata as can't update it on an existing file: 2025-04-19T01:51:01.733666805Z 2025/04/19 01:51:02 INFO : empty metadata sub dir: Updated directory metadata 2025/04/19 01:51:02 DEBUG : Google drive root 'crypt/iktac5oqe17khgjvgdp5oj3naolfecsltrdlansb2vpgjtapv0j0': Skipping btime metadata as can't update it on an existing file: 2025-04-19T01:51:01.733666805Z 2025/04/19 01:51:03 INFO : metadata sub dir: Updated directory metadata 2025/04/19 01:51:03 DEBUG : metadata sub dir/hello metadata world: Need to transfer - File not found at Destination 2025/04/19 01:51:03 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-feyixep3capu': Waiting for checks to finish 2025/04/19 01:51:03 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-feyixep3capu': Waiting for transfers to finish 2025/04/19 01:51:04 DEBUG : metadata sub dir/hello metadata world: md5 = c4f9b19c3a443f8a06e52d70301e95a7 OK 2025/04/19 01:51:04 INFO : metadata sub dir/hello metadata world: Copied (new) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-feyixep3capu'", Local "Local file system at /tmp/rclone3509792376", Modify Window "1ms" 2025/04/19 01:51:07 DEBUG : fg45q1rm3kh00nmmkk4m6ihmrcnel1p7551kqhjr9bk2gtd2gbf0: Rmdir: contains trashed file: "dmuvulfij81f693ur0f1vvbvq9v6iscp56daas3m51n9li5e3470" --- PASS: TestCopyMetadata (7.27s) === RUN TestCopyMetadataNoEmptyDirs run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-feyixep3capu'", Local "Local file system at /tmp/rclone3509792376", Modify Window "1ms" 2025/04/19 01:51:09 DEBUG : metadata sub dir: Making directory with metadata 2025/04/19 01:51:09 INFO : metadata sub dir: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2025/04/19 01:51:09 DEBUG : empty metadata sub dir: Making directory with metadata 2025/04/19 01:51:09 INFO : empty metadata sub dir: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2025/04/19 01:51:09 DEBUG : Local file system at /tmp/rclone3509792376: File to upload is small (21 bytes), uploading instead of streaming 2025/04/19 01:51:09 DEBUG : metadata sub dir/hello metadata world: md5 = baa7a013449dbba2b1ed02b5cfb4e1a2 OK 2025/04/19 01:51:09 DEBUG : metadata sub dir/hello metadata world: Size and md5 of src and dst objects identical 2025/04/19 01:51:09 INFO : metadata sub dir: Set directory modification time (using DirSetModTime) 2025/04/19 01:51:09 DEBUG : Added delayed dir = "empty metadata sub dir", newDst= 2025/04/19 01:51:09 DEBUG : Added delayed dir = "metadata sub dir", newDst= 2025/04/19 01:51:09 DEBUG : metadata sub dir/hello metadata world: Need to transfer - File not found at Destination 2025/04/19 01:51:09 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-feyixep3capu': Waiting for checks to finish 2025/04/19 01:51:09 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-feyixep3capu': Waiting for transfers to finish 2025/04/19 01:51:11 DEBUG : metadata sub dir/hello metadata world: md5 = c70e2f89a691d94ac1d305cd8b206ab5 OK 2025/04/19 01:51:11 INFO : metadata sub dir/hello metadata world: Copied (new) 2025/04/19 01:51:11 DEBUG : Google drive root 'crypt/iktac5oqe17khgjvgdp5oj3naolfecsltrdlansb2vpgjtapv0j0': Skipping btime metadata as can't update it on an existing file: 2025-04-19T01:51:09.005668351Z 2025/04/19 01:51:11 INFO : metadata sub dir: Updated directory metadata run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-feyixep3capu'", Local "Local file system at /tmp/rclone3509792376", Modify Window "1ms" 2025/04/19 01:51:14 DEBUG : fg45q1rm3kh00nmmkk4m6ihmrcnel1p7551kqhjr9bk2gtd2gbf0: Rmdir: contains trashed file: "dmuvulfij81f693ur0f1vvbvq9v6iscp56daas3m51n9li5e3470" --- PASS: TestCopyMetadataNoEmptyDirs (6.54s) === RUN TestCopyMissingDirectory run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-feyixep3capu'", Local "Local file system at /tmp/rclone3509792376", Modify Window "1ms" 2025/04/19 01:51:15 DEBUG : Creating backend with remote "/non-existing" 2025/04/19 01:51:15 ERROR : Local file system at /non-existing: error reading source root directory: directory not found 2025/04/19 01:51:15 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-feyixep3capu': Waiting for checks to finish 2025/04/19 01:51:15 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-feyixep3capu': Waiting for transfers to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-feyixep3capu'", Local "Local file system at /tmp/rclone3509792376", Modify Window "1ms" --- PASS: TestCopyMissingDirectory (1.04s) === RUN TestCopyNoTraverse run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-feyixep3capu'", Local "Local file system at /tmp/rclone3509792376", Modify Window "1ms" 2025/04/19 01:51:16 DEBUG : Added delayed dir = "sub dir", newDst= 2025/04/19 01:51:16 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2025/04/19 01:51:16 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-feyixep3capu': Waiting for checks to finish 2025/04/19 01:51:16 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-feyixep3capu': Waiting for transfers to finish 2025/04/19 01:51:18 DEBUG : sub dir/hello world: md5 = dc1c1df8f9670ac565f6e35e9270c35d OK 2025/04/19 01:51:18 INFO : sub dir/hello world: Copied (new) 2025/04/19 01:51:19 INFO : sub dir: Set directory modification time (using DirSetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-feyixep3capu'", Local "Local file system at /tmp/rclone3509792376", Modify Window "1ms" 2025/04/19 01:51:20 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestCopyNoTraverse (5.45s) === RUN TestCopyCheckFirst run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-feyixep3capu'", Local "Local file system at /tmp/rclone3509792376", Modify Window "1ms" 2025/04/19 01:51:22 INFO : Encrypted drive 'TestCryptDrive:rclone-test-feyixep3capu': Running all checks before starting transfers 2025/04/19 01:51:22 DEBUG : Added delayed dir = "sub dir", newDst= 2025/04/19 01:51:22 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2025/04/19 01:51:22 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-feyixep3capu': Waiting for checks to finish 2025/04/19 01:51:22 INFO : Encrypted drive 'TestCryptDrive:rclone-test-feyixep3capu': Checks finished, now starting transfers 2025/04/19 01:51:22 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-feyixep3capu': Waiting for transfers to finish 2025/04/19 01:51:24 DEBUG : sub dir/hello world: md5 = 35caf5dc8f6e2af1705ca939aed133d9 OK 2025/04/19 01:51:24 INFO : sub dir/hello world: Copied (new) 2025/04/19 01:51:24 INFO : sub dir: Set directory modification time (using DirSetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-feyixep3capu'", Local "Local file system at /tmp/rclone3509792376", Modify Window "1ms" 2025/04/19 01:51:26 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestCopyCheckFirst (5.40s) === RUN TestSyncNoTraverse run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-feyixep3capu'", Local "Local file system at /tmp/rclone3509792376", Modify Window "1ms" 2025/04/19 01:51:27 ERROR : Ignoring --no-traverse with sync 2025/04/19 01:51:27 DEBUG : Added delayed dir = "sub dir", newDst= 2025/04/19 01:51:27 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2025/04/19 01:51:27 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-feyixep3capu': Waiting for checks to finish 2025/04/19 01:51:27 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-feyixep3capu': Waiting for transfers to finish 2025/04/19 01:51:29 DEBUG : sub dir/hello world: md5 = 57e163e08a40ee54042dbec2a84cf1af OK 2025/04/19 01:51:29 INFO : sub dir/hello world: Copied (new) 2025/04/19 01:51:29 DEBUG : Waiting for deletions to finish 2025/04/19 01:51:30 INFO : sub dir: Set directory modification time (using DirSetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-feyixep3capu'", Local "Local file system at /tmp/rclone3509792376", Modify Window "1ms" 2025/04/19 01:51:31 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestSyncNoTraverse (5.49s) === RUN TestCopyWithDepth run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-feyixep3capu'", Local "Local file system at /tmp/rclone3509792376", Modify Window "1ms" 2025/04/19 01:51:33 DEBUG : hello world2: Need to transfer - File not found at Destination 2025/04/19 01:51:33 DEBUG : Added delayed dir = "sub dir", newDst= 2025/04/19 01:51:33 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-feyixep3capu': Waiting for checks to finish 2025/04/19 01:51:33 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-feyixep3capu': Waiting for transfers to finish 2025/04/19 01:51:34 DEBUG : hello world2: md5 = 719fdc95a45932f0ac7058d98b5eb928 OK 2025/04/19 01:51:34 INFO : hello world2: Copied (new) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-feyixep3capu'", Local "Local file system at /tmp/rclone3509792376", Modify Window "1ms" --- PASS: TestCopyWithDepth (3.17s) === RUN TestCopyWithFilesFrom run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-feyixep3capu'", Local "Local file system at /tmp/rclone3509792376", Modify Window "1ms" 2025/04/19 01:51:36 DEBUG : potato2: Need to transfer - File not found at Destination 2025/04/19 01:51:36 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-feyixep3capu': Waiting for checks to finish 2025/04/19 01:51:36 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-feyixep3capu': Waiting for transfers to finish 2025/04/19 01:51:37 DEBUG : potato2: md5 = ada0e524f9a59269eed01e8ccffd94b0 OK 2025/04/19 01:51:37 INFO : potato2: Copied (new) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-feyixep3capu'", Local "Local file system at /tmp/rclone3509792376", Modify Window "1ms" --- PASS: TestCopyWithFilesFrom (3.13s) === RUN TestCopyWithFilesFromAndNoTraverse run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-feyixep3capu'", Local "Local file system at /tmp/rclone3509792376", Modify Window "1ms" 2025/04/19 01:51:39 DEBUG : potato2: Need to transfer - File not found at Destination 2025/04/19 01:51:39 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-feyixep3capu': Waiting for checks to finish 2025/04/19 01:51:39 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-feyixep3capu': Waiting for transfers to finish 2025/04/19 01:51:40 DEBUG : potato2: md5 = d78c8cb1ab02c5cb138dd17865330ef7 OK 2025/04/19 01:51:40 INFO : potato2: Copied (new) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-feyixep3capu'", Local "Local file system at /tmp/rclone3509792376", Modify Window "1ms" --- PASS: TestCopyWithFilesFromAndNoTraverse (3.17s) === RUN TestCopyEmptyDirectories run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-feyixep3capu'", Local "Local file system at /tmp/rclone3509792376", Modify Window "1ms" 2025/04/19 01:51:42 DEBUG : sub dir2/sub sub dir2: Making directory with metadata 2025/04/19 01:51:42 INFO : sub dir2/sub sub dir2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2025/04/19 01:51:42 INFO : sub dir2: Set directory modification time (using DirSetModTime) 2025/04/19 01:51:42 INFO : sub dir: Set directory modification time (using DirSetModTime) 2025/04/19 01:51:42 DEBUG : sub dir: Making directory with metadata 2025/04/19 01:51:43 INFO : sub dir: Made directory with metadata (mtime=2001-02-03T04:05:06.499999999Z) 2025/04/19 01:51:43 DEBUG : sub dir2: Making directory with metadata 2025/04/19 01:51:44 INFO : sub dir2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2025/04/19 01:51:44 DEBUG : sub dir2/sub sub dir2: Making directory with metadata 2025/04/19 01:51:44 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2025/04/19 01:51:44 INFO : sub dir2/sub sub dir2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2025/04/19 01:51:44 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-feyixep3capu': Waiting for checks to finish 2025/04/19 01:51:44 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-feyixep3capu': Waiting for transfers to finish 2025/04/19 01:51:45 DEBUG : sub dir/hello world: md5 = dda31e31df0b167b97beb32c1e55764b OK 2025/04/19 01:51:45 INFO : sub dir/hello world: Copied (new) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-feyixep3capu'", Local "Local file system at /tmp/rclone3509792376", Modify Window "1ms" 2025/04/19 01:51:49 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc: Rmdir: contains trashed file: "cv6a9uf28ngrajena8kt5ijjn0" 2025/04/19 01:51:49 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestCopyEmptyDirectories (8.59s) === RUN TestCopyNoEmptyDirectories run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-feyixep3capu'", Local "Local file system at /tmp/rclone3509792376", Modify Window "1ms" 2025/04/19 01:51:50 INFO : sub dir2: Making directory 2025/04/19 01:51:50 DEBUG : sub dir2/sub sub dir2: Making directory with metadata 2025/04/19 01:51:50 INFO : sub dir2/sub sub dir2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2025/04/19 01:51:51 DEBUG : Added delayed dir = "sub dir", newDst= 2025/04/19 01:51:51 DEBUG : Added delayed dir = "sub dir2", newDst= 2025/04/19 01:51:51 DEBUG : Added delayed dir = "sub dir2/sub sub dir2", newDst= 2025/04/19 01:51:51 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2025/04/19 01:51:51 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-feyixep3capu': Waiting for checks to finish 2025/04/19 01:51:51 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-feyixep3capu': Waiting for transfers to finish 2025/04/19 01:51:53 DEBUG : sub dir/hello world: md5 = 6bbfae92c7aae26b230729f638bbb5e4 OK 2025/04/19 01:51:53 INFO : sub dir/hello world: Copied (new) 2025/04/19 01:51:53 INFO : sub dir: Set directory modification time (using DirSetModTime) 2025/04/19 01:51:55 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestCopyNoEmptyDirectories (4.89s) === RUN TestMoveEmptyDirectories run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-feyixep3capu'", Local "Local file system at /tmp/rclone3509792376", Modify Window "1ms" 2025/04/19 01:51:55 DEBUG : sub dir2: Making directory with metadata 2025/04/19 01:51:55 INFO : sub dir2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2025/04/19 01:51:56 DEBUG : sub dir: Making directory with metadata 2025/04/19 01:51:56 INFO : sub dir: Made directory with metadata (mtime=2025-04-19T01:51:55.873680859Z) 2025/04/19 01:51:56 DEBUG : sub dir2: Making directory with metadata 2025/04/19 01:51:57 INFO : sub dir2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2025/04/19 01:51:57 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2025/04/19 01:51:57 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-feyixep3capu': Waiting for checks to finish 2025/04/19 01:51:57 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-feyixep3capu': Waiting for transfers to finish 2025/04/19 01:51:58 DEBUG : sub dir/hello world: md5 = bec7522981f40911dfa7afb6090f1c0b OK 2025/04/19 01:51:58 INFO : sub dir/hello world: Copied (new) 2025/04/19 01:51:58 INFO : sub dir/hello world: Deleted run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-feyixep3capu'", Local "Local file system at /tmp/rclone3509792376", Modify Window "1ms" 2025/04/19 01:52:01 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestMoveEmptyDirectories (6.71s) === RUN TestSyncNoUpdateDirModtime run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-feyixep3capu'", Local "Local file system at /tmp/rclone3509792376", Modify Window "1ms" 2025/04/19 01:52:02 DEBUG : sub dir no update dir modtime: Making directory with metadata 2025/04/19 01:52:02 INFO : sub dir no update dir modtime: Made directory with metadata (mtime=2001-02-03T04:05:06.499999999Z) 2025/04/19 01:52:03 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-feyixep3capu': Waiting for checks to finish 2025/04/19 01:52:03 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-feyixep3capu': Waiting for transfers to finish 2025/04/19 01:52:03 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-feyixep3capu'", Local "Local file system at /tmp/rclone3509792376", Modify Window "1ms" --- PASS: TestSyncNoUpdateDirModtime (3.81s) === RUN TestMoveNoEmptyDirectories run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-feyixep3capu'", Local "Local file system at /tmp/rclone3509792376", Modify Window "1ms" 2025/04/19 01:52:06 INFO : sub dir2: Making directory 2025/04/19 01:52:06 DEBUG : Added delayed dir = "sub dir", newDst= 2025/04/19 01:52:06 DEBUG : Added delayed dir = "sub dir2", newDst= 2025/04/19 01:52:06 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2025/04/19 01:52:06 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-feyixep3capu': Waiting for checks to finish 2025/04/19 01:52:06 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-feyixep3capu': Waiting for transfers to finish 2025/04/19 01:52:08 DEBUG : sub dir/hello world: md5 = 2641c28a38573b87c9c96b2aaff66b30 OK 2025/04/19 01:52:08 INFO : sub dir/hello world: Copied (new) 2025/04/19 01:52:08 INFO : sub dir/hello world: Deleted 2025/04/19 01:52:09 INFO : sub dir: Set directory modification time (using DirSetModTime) 2025/04/19 01:52:10 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestMoveNoEmptyDirectories (5.05s) === RUN TestSyncEmptyDirectories run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-feyixep3capu'", Local "Local file system at /tmp/rclone3509792376", Modify Window "1ms" 2025/04/19 01:52:11 DEBUG : sub dir2: Making directory with metadata 2025/04/19 01:52:11 INFO : sub dir2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2025/04/19 01:52:11 INFO : sub dir: Set directory modification time (using DirSetModTime) 2025/04/19 01:52:11 DEBUG : sub dir: Making directory with metadata 2025/04/19 01:52:12 INFO : sub dir: Made directory with metadata (mtime=2001-02-03T04:05:06.499999999Z) 2025/04/19 01:52:12 DEBUG : sub dir2: Making directory with metadata 2025/04/19 01:52:13 INFO : sub dir2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2025/04/19 01:52:13 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2025/04/19 01:52:13 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-feyixep3capu': Waiting for checks to finish 2025/04/19 01:52:13 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-feyixep3capu': Waiting for transfers to finish 2025/04/19 01:52:14 DEBUG : sub dir/hello world: md5 = d2c2cfbaa0a88c32b03e6a6dc75069c2 OK 2025/04/19 01:52:14 INFO : sub dir/hello world: Copied (new) 2025/04/19 01:52:14 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-feyixep3capu'", Local "Local file system at /tmp/rclone3509792376", Modify Window "1ms" 2025/04/19 01:52:17 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestSyncEmptyDirectories (7.07s) === RUN TestSyncSetDelayedModTimes run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-feyixep3capu'", Local "Local file system at /tmp/rclone3509792376", Modify Window "1ms" sync_test.go:507: Backend doesn't have DirModTimeUpdatesOnWrite set --- SKIP: TestSyncSetDelayedModTimes (0.42s) === RUN TestSyncNoEmptyDirectories run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-feyixep3capu'", Local "Local file system at /tmp/rclone3509792376", Modify Window "1ms" 2025/04/19 01:52:18 INFO : sub dir2: Making directory 2025/04/19 01:52:19 DEBUG : Added delayed dir = "sub dir", newDst= 2025/04/19 01:52:19 DEBUG : Added delayed dir = "sub dir2", newDst= 2025/04/19 01:52:19 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2025/04/19 01:52:19 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-feyixep3capu': Waiting for checks to finish 2025/04/19 01:52:19 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-feyixep3capu': Waiting for transfers to finish 2025/04/19 01:52:21 DEBUG : sub dir/hello world: md5 = 502bc2e54a8ca39ba748ac0bcbdbcdfe OK 2025/04/19 01:52:21 INFO : sub dir/hello world: Copied (new) 2025/04/19 01:52:21 DEBUG : Waiting for deletions to finish 2025/04/19 01:52:21 INFO : sub dir: Set directory modification time (using DirSetModTime) 2025/04/19 01:52:23 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestSyncNoEmptyDirectories (5.13s) === RUN TestServerSideCopy run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-feyixep3capu'", Local "Local file system at /tmp/rclone3509792376", Modify Window "1ms" 2025/04/19 01:52:26 DEBUG : sub dir/hello world: md5 = 1f703b74d982432e13bb708e5f03b83e OK 2025/04/19 01:52:26 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-powokab6qoqe" 2025/04/19 01:52:26 DEBUG : Creating backend with remote "TestDrive:crypt/a5h173ms33lrchck1o94mg47vcgrcuh181l0itcaohi7noep3n80" sync_test.go:590: Server side copy (if possible) Encrypted drive 'TestCryptDrive:rclone-test-feyixep3capu' -> Encrypted drive 'TestCryptDrive:rclone-test-powokab6qoqe' 2025/04/19 01:52:28 DEBUG : Added delayed dir = "sub dir", newDst= 2025/04/19 01:52:28 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2025/04/19 01:52:28 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-powokab6qoqe': Waiting for checks to finish 2025/04/19 01:52:28 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-powokab6qoqe': Waiting for transfers to finish 2025/04/19 01:52:30 INFO : sub dir/hello world: Copied (server-side copy) 2025/04/19 01:52:30 INFO : sub dir: Set directory modification time (using DirSetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-feyixep3capu'", Local "Local file system at /tmp/rclone3509792376", Modify Window "1ms" 2025/04/19 01:52:31 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-powokab6qoqe': Purge remote 2025/04/19 01:52:33 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestServerSideCopy (10.08s) === RUN TestCopyOverSelf run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-feyixep3capu'", Local "Local file system at /tmp/rclone3509792376", Modify Window "1ms" 2025/04/19 01:52:36 DEBUG : sub dir/hello world: md5 = 86910add1d44e9d2892a0923b5a5a71c OK 2025/04/19 01:52:37 INFO : sub dir: Set directory modification time (using SetModTime) 2025/04/19 01:52:37 DEBUG : Added delayed dir = "sub dir", newDst=sub dir 2025/04/19 01:52:37 DEBUG : sub dir/hello world: Sizes differ (src 17 vs dst 11) 2025/04/19 01:52:37 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-feyixep3capu': Waiting for checks to finish 2025/04/19 01:52:37 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-feyixep3capu': Waiting for transfers to finish 2025/04/19 01:52:38 DEBUG : sub dir/hello world: md5 = 1d571cb5b9b486c01b3a2c0023b9355e OK 2025/04/19 01:52:38 INFO : sub dir/hello world: Copied (replaced existing) 2025/04/19 01:52:38 INFO : sub dir: Set directory modification time (using SetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-feyixep3capu'", Local "Local file system at /tmp/rclone3509792376", Modify Window "1ms" 2025/04/19 01:52:40 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestCopyOverSelf (7.55s) === RUN TestServerSideCopyOverSelf run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-feyixep3capu'", Local "Local file system at /tmp/rclone3509792376", Modify Window "1ms" 2025/04/19 01:52:43 DEBUG : sub dir/hello world: md5 = c8a056414272c29fccd31aab90be75a7 OK 2025/04/19 01:52:44 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-jusabur4bodu" 2025/04/19 01:52:44 DEBUG : Creating backend with remote "TestDrive:crypt/u1tsoiimt60f5ktakrs8pa7gbq0huknv3bq5hhmpjqp6svlmrg6g" sync_test.go:626: Server side copy (if possible) Encrypted drive 'TestCryptDrive:rclone-test-feyixep3capu' -> Encrypted drive 'TestCryptDrive:rclone-test-jusabur4bodu' 2025/04/19 01:52:45 DEBUG : Added delayed dir = "sub dir", newDst= 2025/04/19 01:52:45 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2025/04/19 01:52:45 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-jusabur4bodu': Waiting for checks to finish 2025/04/19 01:52:45 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-jusabur4bodu': Waiting for transfers to finish 2025/04/19 01:52:48 INFO : sub dir/hello world: Copied (server-side copy) 2025/04/19 01:52:48 INFO : sub dir: Set directory modification time (using DirSetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-feyixep3capu'", Local "Local file system at /tmp/rclone3509792376", Modify Window "1ms" 2025/04/19 01:52:50 DEBUG : sub dir/hello world: md5 = e5ff5931aae8bc98b50e4681c1d7a3f0 OK 2025/04/19 01:52:51 DEBUG : sub dir: Directory modification time the same (differ by 0s, within tolerance 1ms) 2025/04/19 01:52:51 DEBUG : Added delayed dir = "sub dir", newDst=sub dir 2025/04/19 01:52:51 DEBUG : sub dir/hello world: Sizes differ (src 17 vs dst 11) 2025/04/19 01:52:51 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-jusabur4bodu': Waiting for checks to finish 2025/04/19 01:52:51 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-jusabur4bodu': Waiting for transfers to finish 2025/04/19 01:52:52 INFO : sub dir/hello world: Copied (server-side copy) 2025/04/19 01:52:53 INFO : sub dir: Set directory modification time (using SetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-feyixep3capu'", Local "Local file system at /tmp/rclone3509792376", Modify Window "1ms" 2025/04/19 01:52:53 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-jusabur4bodu': Purge remote 2025/04/19 01:52:55 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestServerSideCopyOverSelf (15.03s) === RUN TestMoveOverSelf run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-feyixep3capu'", Local "Local file system at /tmp/rclone3509792376", Modify Window "1ms" 2025/04/19 01:52:58 DEBUG : sub dir/hello world: md5 = 08e2f208fd490d7c8bd50667fd8a70f6 OK 2025/04/19 01:53:00 INFO : sub dir: Set directory modification time (using SetModTime) 2025/04/19 01:53:00 DEBUG : Added delayed dir = "sub dir", newDst=sub dir 2025/04/19 01:53:00 DEBUG : sub dir/hello world: Sizes differ (src 17 vs dst 11) 2025/04/19 01:53:00 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-feyixep3capu': Waiting for checks to finish 2025/04/19 01:53:00 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-feyixep3capu': Waiting for transfers to finish 2025/04/19 01:53:01 DEBUG : sub dir/hello world: md5 = 576dbcb6afd394cf78b5c1b30d6aed09 OK 2025/04/19 01:53:01 INFO : sub dir/hello world: Copied (replaced existing) 2025/04/19 01:53:01 INFO : sub dir/hello world: Deleted 2025/04/19 01:53:01 INFO : sub dir: Set directory modification time (using SetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-feyixep3capu'", Local "Local file system at /tmp/rclone3509792376", Modify Window "1ms" 2025/04/19 01:53:03 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestMoveOverSelf (7.88s) === RUN TestServerSideMoveOverSelf run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-feyixep3capu'", Local "Local file system at /tmp/rclone3509792376", Modify Window "1ms" 2025/04/19 01:53:06 DEBUG : sub dir/hello world: md5 = 0b2f6dbb63e903cbf604b16829c0ec7b OK 2025/04/19 01:53:07 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-vikazob9pugi" 2025/04/19 01:53:07 DEBUG : Creating backend with remote "TestDrive:crypt/mmgtlvuq7ppllofps1icnftde5oqmnvics1m9m3csvq17dtpgqlg" sync_test.go:671: Server side copy (if possible) Encrypted drive 'TestCryptDrive:rclone-test-feyixep3capu' -> Encrypted drive 'TestCryptDrive:rclone-test-vikazob9pugi' 2025/04/19 01:53:08 DEBUG : Added delayed dir = "sub dir", newDst= 2025/04/19 01:53:08 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2025/04/19 01:53:08 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vikazob9pugi': Waiting for checks to finish 2025/04/19 01:53:08 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vikazob9pugi': Waiting for transfers to finish 2025/04/19 01:53:10 INFO : sub dir/hello world: Copied (server-side copy) 2025/04/19 01:53:11 INFO : sub dir: Set directory modification time (using DirSetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-feyixep3capu'", Local "Local file system at /tmp/rclone3509792376", Modify Window "1ms" 2025/04/19 01:53:13 DEBUG : sub dir/hello world: md5 = 194ea61583576dbc898644a1f3483af9 OK 2025/04/19 01:53:13 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vikazob9pugi': Using server-side directory move 2025/04/19 01:53:13 INFO : Encrypted drive 'TestCryptDrive:rclone-test-vikazob9pugi': Server side directory move failed - fallback to file moves: can't copy directory - destination already exists 2025/04/19 01:53:14 DEBUG : sub dir: Directory modification time the same (differ by 0s, within tolerance 1ms) 2025/04/19 01:53:14 DEBUG : Added delayed dir = "sub dir", newDst=sub dir 2025/04/19 01:53:14 DEBUG : sub dir/hello world: Sizes differ (src 17 vs dst 11) 2025/04/19 01:53:14 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vikazob9pugi': Waiting for checks to finish 2025/04/19 01:53:14 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vikazob9pugi': Waiting for transfers to finish 2025/04/19 01:53:14 INFO : sub dir/hello world: Deleted 2025/04/19 01:53:15 INFO : sub dir/hello world: Moved (server-side) 2025/04/19 01:53:15 INFO : sub dir: Set directory modification time (using SetModTime) 2025/04/19 01:53:17 DEBUG : sub dir/hello world: md5 = dbafb006830d5b1aa4689450cbb21b19 OK 2025/04/19 01:53:18 DEBUG : testing file moves 2025/04/19 01:53:18 DEBUG : sub dir: Directory modification time the same (differ by 0s, within tolerance 1ms) 2025/04/19 01:53:18 DEBUG : Added delayed dir = "sub dir", newDst=sub dir 2025/04/19 01:53:18 DEBUG : sub dir/hello world: Sizes differ (src 24 vs dst 17) 2025/04/19 01:53:18 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vikazob9pugi': Waiting for checks to finish 2025/04/19 01:53:18 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vikazob9pugi': Waiting for transfers to finish 2025/04/19 01:53:18 INFO : sub dir/hello world: Deleted 2025/04/19 01:53:19 INFO : sub dir/hello world: Moved (server-side) 2025/04/19 01:53:20 INFO : sub dir: Set directory modification time (using SetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-feyixep3capu'", Local "Local file system at /tmp/rclone3509792376", Modify Window "1ms" 2025/04/19 01:53:20 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vikazob9pugi': Purge remote --- PASS: TestServerSideMoveOverSelf (18.95s) === RUN TestCopyAfterDelete run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-feyixep3capu'", Local "Local file system at /tmp/rclone3509792376", Modify Window "1ms" 2025/04/19 01:53:25 DEBUG : sub dir/hello world: md5 = 4e991d5f189dc852d75c2cc3bd31906c OK 2025/04/19 01:53:25 ERROR : : error listing: directory not found 2025/04/19 01:53:26 INFO : Local file system at /tmp/rclone3509792376: Making directory 2025/04/19 01:53:26 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-feyixep3capu': Waiting for checks to finish 2025/04/19 01:53:26 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-feyixep3capu': Waiting for transfers to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-feyixep3capu'", Local "Local file system at /tmp/rclone3509792376", Modify Window "1ms" 2025/04/19 01:53:28 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestCopyAfterDelete (5.65s) === RUN TestCopyRedownload run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-feyixep3capu'", Local "Local file system at /tmp/rclone3509792376", Modify Window "1ms" 2025/04/19 01:53:31 DEBUG : sub dir/hello world: md5 = 1ba2ba62a3f38d26b2f7a1f0bb8c65b8 OK 2025/04/19 01:53:32 DEBUG : Added delayed dir = "sub dir", newDst= 2025/04/19 01:53:32 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2025/04/19 01:53:32 DEBUG : Local file system at /tmp/rclone3509792376: Waiting for checks to finish 2025/04/19 01:53:32 DEBUG : Local file system at /tmp/rclone3509792376: Waiting for transfers to finish 2025/04/19 01:53:32 DEBUG : sub dir/hello world.285f0a30.partial: renamed to: sub dir/hello world 2025/04/19 01:53:32 INFO : sub dir/hello world: Copied (new) 2025/04/19 01:53:32 INFO : sub dir: Set directory modification time (using DirSetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-feyixep3capu'", Local "Local file system at /tmp/rclone3509792376", Modify Window "1ms" 2025/04/19 01:53:33 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestCopyRedownload (5.74s) === RUN TestSyncBasedOnCheckSum run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-feyixep3capu'", Local "Local file system at /tmp/rclone3509792376", Modify Window "1ms" 2025/04/19 01:53:35 DEBUG : check sum: Need to transfer - File not found at Destination 2025/04/19 01:53:35 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-feyixep3capu': Waiting for checks to finish 2025/04/19 01:53:35 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-feyixep3capu': Waiting for transfers to finish 2025/04/19 01:53:36 DEBUG : check sum: md5 = ef75260c3c8ba12f9b132a3eeeaa88bc OK 2025/04/19 01:53:36 INFO : check sum: Copied (new) 2025/04/19 01:53:36 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-feyixep3capu'", Local "Local file system at /tmp/rclone3509792376", Modify Window "1ms" 2025/04/19 01:53:36 NOTICE: Encrypted drive 'TestCryptDrive:rclone-test-feyixep3capu': --checksum is in use but the source and destination have no hashes in common; falling back to --size-only 2025/04/19 01:53:36 DEBUG : check sum: Size of src and dst objects identical 2025/04/19 01:53:36 DEBUG : check sum: Unchanged skipping 2025/04/19 01:53:36 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-feyixep3capu': Waiting for checks to finish 2025/04/19 01:53:36 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-feyixep3capu': Waiting for transfers to finish 2025/04/19 01:53:36 DEBUG : Waiting for deletions to finish 2025/04/19 01:53:36 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-feyixep3capu'", Local "Local file system at /tmp/rclone3509792376", Modify Window "1ms" --- PASS: TestSyncBasedOnCheckSum (4.01s) === RUN TestSyncSizeOnly run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-feyixep3capu'", Local "Local file system at /tmp/rclone3509792376", Modify Window "1ms" 2025/04/19 01:53:39 DEBUG : sizeonly: Need to transfer - File not found at Destination 2025/04/19 01:53:39 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-feyixep3capu': Waiting for checks to finish 2025/04/19 01:53:39 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-feyixep3capu': Waiting for transfers to finish 2025/04/19 01:53:40 DEBUG : sizeonly: md5 = 85b9c1cf3da839767276ee986045b776 OK 2025/04/19 01:53:40 INFO : sizeonly: Copied (new) 2025/04/19 01:53:40 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-feyixep3capu'", Local "Local file system at /tmp/rclone3509792376", Modify Window "1ms" 2025/04/19 01:53:41 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-feyixep3capu': Waiting for checks to finish 2025/04/19 01:53:41 DEBUG : sizeonly: Sizes identical 2025/04/19 01:53:41 DEBUG : sizeonly: Unchanged skipping 2025/04/19 01:53:41 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-feyixep3capu': Waiting for transfers to finish 2025/04/19 01:53:41 DEBUG : Waiting for deletions to finish 2025/04/19 01:53:41 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-feyixep3capu'", Local "Local file system at /tmp/rclone3509792376", Modify Window "1ms" --- PASS: TestSyncSizeOnly (4.17s) === RUN TestSyncIgnoreSize run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-feyixep3capu'", Local "Local file system at /tmp/rclone3509792376", Modify Window "1ms" 2025/04/19 01:53:43 DEBUG : ignore-size: Need to transfer - File not found at Destination 2025/04/19 01:53:43 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-feyixep3capu': Waiting for checks to finish 2025/04/19 01:53:43 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-feyixep3capu': Waiting for transfers to finish 2025/04/19 01:53:44 DEBUG : ignore-size: md5 = 5e544943fe3ae2eb0a8cf3d1a96566af OK 2025/04/19 01:53:44 INFO : ignore-size: Copied (new) 2025/04/19 01:53:44 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-feyixep3capu'", Local "Local file system at /tmp/rclone3509792376", Modify Window "1ms" 2025/04/19 01:53:45 DEBUG : ignore-size: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/19 01:53:45 DEBUG : ignore-size: Unchanged skipping 2025/04/19 01:53:45 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-feyixep3capu': Waiting for checks to finish 2025/04/19 01:53:45 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-feyixep3capu': Waiting for transfers to finish 2025/04/19 01:53:45 DEBUG : Waiting for deletions to finish 2025/04/19 01:53:45 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-feyixep3capu'", Local "Local file system at /tmp/rclone3509792376", Modify Window "1ms" --- PASS: TestSyncIgnoreSize (3.96s) === RUN TestSyncIgnoreTimes run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-feyixep3capu'", Local "Local file system at /tmp/rclone3509792376", Modify Window "1ms" 2025/04/19 01:53:48 DEBUG : existing: md5 = 28992a9406490d0868f1b3444fbd0046 OK 2025/04/19 01:53:48 DEBUG : existing: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/19 01:53:48 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-feyixep3capu': Waiting for checks to finish 2025/04/19 01:53:48 DEBUG : existing: Unchanged skipping 2025/04/19 01:53:48 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-feyixep3capu': Waiting for transfers to finish 2025/04/19 01:53:48 DEBUG : Waiting for deletions to finish 2025/04/19 01:53:48 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-feyixep3capu'", Local "Local file system at /tmp/rclone3509792376", Modify Window "1ms" 2025/04/19 01:53:49 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-feyixep3capu': Waiting for checks to finish 2025/04/19 01:53:49 DEBUG : existing: Transferring unconditionally as --ignore-times is in use 2025/04/19 01:53:49 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-feyixep3capu': Waiting for transfers to finish 2025/04/19 01:53:50 DEBUG : existing: md5 = ad1660142585ae97831e87fcc997ab89 OK 2025/04/19 01:53:50 INFO : existing: Copied (replaced existing) 2025/04/19 01:53:50 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-feyixep3capu'", Local "Local file system at /tmp/rclone3509792376", Modify Window "1ms" --- PASS: TestSyncIgnoreTimes (5.10s) === RUN TestSyncIgnoreExisting run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-feyixep3capu'", Local "Local file system at /tmp/rclone3509792376", Modify Window "1ms" 2025/04/19 01:53:52 DEBUG : existing: Need to transfer - File not found at Destination 2025/04/19 01:53:52 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-feyixep3capu': Waiting for checks to finish 2025/04/19 01:53:52 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-feyixep3capu': Waiting for transfers to finish 2025/04/19 01:53:53 DEBUG : existing: md5 = 5d1a5b50e019a1485df1270f6a8eddfe OK 2025/04/19 01:53:53 INFO : existing: Copied (new) 2025/04/19 01:53:53 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-feyixep3capu'", Local "Local file system at /tmp/rclone3509792376", Modify Window "1ms" 2025/04/19 01:53:54 DEBUG : existing: Destination exists, skipping 2025/04/19 01:53:54 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-feyixep3capu': Waiting for checks to finish 2025/04/19 01:53:54 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-feyixep3capu': Waiting for transfers to finish 2025/04/19 01:53:54 DEBUG : Waiting for deletions to finish 2025/04/19 01:53:54 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-feyixep3capu'", Local "Local file system at /tmp/rclone3509792376", Modify Window "1ms" --- PASS: TestSyncIgnoreExisting (4.03s) === RUN TestSyncIgnoreErrors run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-feyixep3capu'", Local "Local file system at /tmp/rclone3509792376", Modify Window "1ms" 2025/04/19 01:53:58 DEBUG : b/potato: md5 = b206e5496f747e0bb99f90f8f6c51d67 OK 2025/04/19 01:54:00 DEBUG : c/non empty space: md5 = a13c788e36ed3b3006b8958788224c6d OK 2025/04/19 01:54:00 INFO : d: Making directory 2025/04/19 01:54:02 DEBUG : Added delayed dir = "a", newDst= 2025/04/19 01:54:02 INFO : c: Set directory modification time (using SetModTime) 2025/04/19 01:54:02 DEBUG : Added delayed dir = "c", newDst=c 2025/04/19 01:54:02 DEBUG : c/non empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/04/19 01:54:02 DEBUG : a/potato2: Need to transfer - File not found at Destination 2025/04/19 01:54:02 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-feyixep3capu': Waiting for checks to finish 2025/04/19 01:54:02 DEBUG : c/non empty space: Unchanged skipping 2025/04/19 01:54:02 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-feyixep3capu': Waiting for transfers to finish 2025/04/19 01:54:04 DEBUG : a/potato2: md5 = 1d657e0bd34e4ded0bb52f586a9b905c OK 2025/04/19 01:54:04 INFO : a/potato2: Copied (new) 2025/04/19 01:54:04 DEBUG : Waiting for deletions to finish 2025/04/19 01:54:05 INFO : b/potato: Deleted 2025/04/19 01:54:05 INFO : a: Set directory modification time (using DirSetModTime) 2025/04/19 01:54:05 INFO : d: Removing directory 2025/04/19 01:54:06 INFO : b: Removing directory 2025/04/19 01:54:06 DEBUG : 32d8ua6196mc1r7qkfog53rkg0: Rmdir: contains trashed file: "2m507n64kafsi59v9q71r281a4" 2025/04/19 01:54:06 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-feyixep3capu': deleted 2 directories run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-feyixep3capu'", Local "Local file system at /tmp/rclone3509792376", Modify Window "1ms" 2025/04/19 01:54:08 DEBUG : 3i9du405pfogq3ncai6pg7ouio: Rmdir: contains trashed file: "982d3pss7t5pn0il16r2foj31s" 2025/04/19 01:54:09 DEBUG : 2bsvlrk2ne1lfitm6tttcu0qt8: Rmdir: contains trashed file: "89l8renevh3mji1c8r1p7qn6tg" --- PASS: TestSyncIgnoreErrors (14.52s) === RUN TestSyncAfterChangingModtimeOnly run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-feyixep3capu'", Local "Local file system at /tmp/rclone3509792376", Modify Window "1ms" 2025/04/19 01:54:12 DEBUG : empty space: md5 = ea651022194f0847d56f2d268b826719 OK 2025/04/19 01:54:12 DEBUG : empty space: Modification times differ by -95456h54m52.624456789s: 2011-12-25 12:59:59.123456789 +0000 UTC, 2001-02-03 04:05:06.499 +0000 UTC 2025/04/19 01:54:12 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-feyixep3capu': Waiting for checks to finish 2025/04/19 01:54:12 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-feyixep3capu': Waiting for transfers to finish 2025/04/19 01:54:12 NOTICE: empty space: Skipped copy as --dry-run is set (size 1) 2025/04/19 01:54:12 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-feyixep3capu'", Local "Local file system at /tmp/rclone3509792376", Modify Window "1ms" 2025/04/19 01:54:13 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-feyixep3capu': Waiting for checks to finish 2025/04/19 01:54:13 DEBUG : empty space: Modification times differ by -95456h54m52.624456789s: 2011-12-25 12:59:59.123456789 +0000 UTC, 2001-02-03 04:05:06.499 +0000 UTC 2025/04/19 01:54:13 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-feyixep3capu': Waiting for transfers to finish 2025/04/19 01:54:14 DEBUG : empty space: md5 = a34ce72b63c59824c5f531c45bc44826 OK 2025/04/19 01:54:14 INFO : empty space: Copied (replaced existing) 2025/04/19 01:54:14 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-feyixep3capu'", Local "Local file system at /tmp/rclone3509792376", Modify Window "1ms" --- PASS: TestSyncAfterChangingModtimeOnly (5.61s) === RUN TestSyncAfterChangingModtimeOnlyWithNoUpdateModTime run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-feyixep3capu'", Local "Local file system at /tmp/rclone3509792376", Modify Window "1ms" sync_test.go:1016: Can't check this if no hashes supported --- PASS: TestSyncAfterChangingModtimeOnlyWithNoUpdateModTime (0.41s) === RUN TestSyncDoesntUpdateModtime run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-feyixep3capu'", Local "Local file system at /tmp/rclone3509792376", Modify Window "1ms" 2025/04/19 01:54:18 DEBUG : foo: md5 = 3e59177385650abde2fd1424de95a75d OK 2025/04/19 01:54:18 DEBUG : foo: Modification times differ by -95456h54m52.624456789s: 2011-12-25 12:59:59.123456789 +0000 UTC, 2001-02-03 04:05:06.499 +0000 UTC 2025/04/19 01:54:18 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-feyixep3capu': Waiting for checks to finish 2025/04/19 01:54:18 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-feyixep3capu': Waiting for transfers to finish 2025/04/19 01:54:19 DEBUG : foo: md5 = 7450d201fce10e57482d17b2e25d5c77 OK 2025/04/19 01:54:19 INFO : foo: Copied (replaced existing) 2025/04/19 01:54:19 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-feyixep3capu'", Local "Local file system at /tmp/rclone3509792376", Modify Window "1ms" --- PASS: TestSyncDoesntUpdateModtime (4.45s) === RUN TestSyncAfterAddingAFile run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-feyixep3capu'", Local "Local file system at /tmp/rclone3509792376", Modify Window "1ms" 2025/04/19 01:54:22 DEBUG : empty space: md5 = 3098794310426350c18839fff836ddad OK 2025/04/19 01:54:23 DEBUG : empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/04/19 01:54:23 DEBUG : potato: Need to transfer - File not found at Destination 2025/04/19 01:54:23 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-feyixep3capu': Waiting for checks to finish 2025/04/19 01:54:23 DEBUG : empty space: Unchanged skipping 2025/04/19 01:54:23 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-feyixep3capu': Waiting for transfers to finish 2025/04/19 01:54:24 DEBUG : potato: md5 = 1b99a1fd17fdb8525d4711e5832f5898 OK 2025/04/19 01:54:24 INFO : potato: Copied (new) 2025/04/19 01:54:24 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-feyixep3capu'", Local "Local file system at /tmp/rclone3509792376", Modify Window "1ms" --- PASS: TestSyncAfterAddingAFile (5.41s) === RUN TestSyncAfterChangingFilesSizeOnly run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-feyixep3capu'", Local "Local file system at /tmp/rclone3509792376", Modify Window "1ms" 2025/04/19 01:54:27 DEBUG : potato: md5 = 0d544ee797ddd64a4b4b89f84b282075 OK 2025/04/19 01:54:28 DEBUG : potato: Sizes differ (src 21 vs dst 60) 2025/04/19 01:54:28 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-feyixep3capu': Waiting for checks to finish 2025/04/19 01:54:28 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-feyixep3capu': Waiting for transfers to finish 2025/04/19 01:54:29 DEBUG : potato: md5 = 114355c5b1683fb562249998838cd115 OK 2025/04/19 01:54:29 INFO : potato: Copied (replaced existing) 2025/04/19 01:54:29 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-feyixep3capu'", Local "Local file system at /tmp/rclone3509792376", Modify Window "1ms" --- PASS: TestSyncAfterChangingFilesSizeOnly (4.65s) === RUN TestSyncAfterChangingContentsOnly run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-feyixep3capu'", Local "Local file system at /tmp/rclone3509792376", Modify Window "1ms" 2025/04/19 01:54:32 DEBUG : potato: md5 = 932fcccc41a332f62c39bb0993c31c48 OK 2025/04/19 01:54:33 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-feyixep3capu': Waiting for checks to finish 2025/04/19 01:54:33 DEBUG : potato: Modification times differ by 119h59m59.876543211s: 2011-12-25 12:59:59.123456789 +0000 UTC, 2011-12-30 12:59:59 +0000 UTC 2025/04/19 01:54:33 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-feyixep3capu': Waiting for transfers to finish 2025/04/19 01:54:34 DEBUG : potato: md5 = 7b199f1118538f4d8b185a8b633ada88 OK 2025/04/19 01:54:34 INFO : potato: Copied (replaced existing) 2025/04/19 01:54:34 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-feyixep3capu'", Local "Local file system at /tmp/rclone3509792376", Modify Window "1ms" --- PASS: TestSyncAfterChangingContentsOnly (4.52s) === RUN TestSyncAfterRemovingAFileAndAddingAFileDryRun run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-feyixep3capu'", Local "Local file system at /tmp/rclone3509792376", Modify Window "1ms" 2025/04/19 01:54:37 DEBUG : potato: md5 = 679e629f1c50cf7ef780d8fbb92b1808 OK 2025/04/19 01:54:38 DEBUG : empty space: md5 = 93d0528f96226df6441f7aa00c1a7b55 OK 2025/04/19 01:54:38 DEBUG : potato2: Need to transfer - File not found at Destination 2025/04/19 01:54:38 DEBUG : empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/04/19 01:54:38 DEBUG : empty space: Unchanged skipping 2025/04/19 01:54:38 NOTICE: potato2: Skipped copy as --dry-run is set (size 60) 2025/04/19 01:54:38 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-feyixep3capu': Waiting for checks to finish 2025/04/19 01:54:38 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-feyixep3capu': Waiting for transfers to finish 2025/04/19 01:54:38 DEBUG : Waiting for deletions to finish 2025/04/19 01:54:38 NOTICE: potato: Skipped delete as --dry-run is set (size 21) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-feyixep3capu'", Local "Local file system at /tmp/rclone3509792376", Modify Window "1ms" --- PASS: TestSyncAfterRemovingAFileAndAddingAFileDryRun (4.90s) === RUN TestSyncAfterRemovingAFileAndAddingAFile run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-feyixep3capu'", Local "Local file system at /tmp/rclone3509792376", Modify Window "1ms" 2025/04/19 01:54:41 DEBUG : potato: md5 = 46ed88da5939be1a660b0919509b9a52 OK 2025/04/19 01:54:43 DEBUG : empty space: md5 = 4b7835a6c74d7f9e9303424643f5ec7d OK 2025/04/19 01:54:43 DEBUG : empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/04/19 01:54:43 DEBUG : potato2: Need to transfer - File not found at Destination 2025/04/19 01:54:43 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-feyixep3capu': Waiting for checks to finish 2025/04/19 01:54:43 DEBUG : empty space: Unchanged skipping 2025/04/19 01:54:43 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-feyixep3capu': Waiting for transfers to finish 2025/04/19 01:54:45 DEBUG : potato2: md5 = a292f8d901c19c71143da8ab63d63109 OK 2025/04/19 01:54:45 INFO : potato2: Copied (new) 2025/04/19 01:54:45 DEBUG : Waiting for deletions to finish 2025/04/19 01:54:45 INFO : potato: Deleted run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-feyixep3capu'", Local "Local file system at /tmp/rclone3509792376", Modify Window "1ms" --- PASS: TestSyncAfterRemovingAFileAndAddingAFile (6.93s) === RUN TestSyncAfterRemovingAFileAndAddingAFileSubDir run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-feyixep3capu'", Local "Local file system at /tmp/rclone3509792376", Modify Window "1ms" 2025/04/19 01:54:49 DEBUG : b/potato: md5 = 5076fe10ef0bf4b343a8ca11b07d16ca OK 2025/04/19 01:54:51 DEBUG : c/non empty space: md5 = 1e7da84c77fbab801d046c5941c1e707 OK 2025/04/19 01:54:51 INFO : d: Making directory 2025/04/19 01:54:52 INFO : d/e: Making directory 2025/04/19 01:54:54 DEBUG : Added delayed dir = "a", newDst= 2025/04/19 01:54:54 INFO : c: Set directory modification time (using SetModTime) 2025/04/19 01:54:54 DEBUG : Added delayed dir = "c", newDst=c 2025/04/19 01:54:54 DEBUG : c/non empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/04/19 01:54:54 DEBUG : a/potato2: Need to transfer - File not found at Destination 2025/04/19 01:54:54 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-feyixep3capu': Waiting for checks to finish 2025/04/19 01:54:54 DEBUG : c/non empty space: Unchanged skipping 2025/04/19 01:54:54 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-feyixep3capu': Waiting for transfers to finish 2025/04/19 01:54:56 DEBUG : a/potato2: md5 = eaacbf453c5799df752fdcd91ac9d6fa OK 2025/04/19 01:54:56 INFO : a/potato2: Copied (new) 2025/04/19 01:54:56 DEBUG : Waiting for deletions to finish 2025/04/19 01:54:57 INFO : b/potato: Deleted 2025/04/19 01:54:57 INFO : a: Set directory modification time (using DirSetModTime) 2025/04/19 01:54:57 INFO : d/e: Removing directory 2025/04/19 01:54:58 INFO : d: Removing directory 2025/04/19 01:54:58 DEBUG : ka6id8d20d3s5ktapedlphgta8: Rmdir: contains trashed file: "r8sppajuabeak3sbgj2ak8vuf8" 2025/04/19 01:54:59 INFO : b: Removing directory 2025/04/19 01:54:59 DEBUG : 32d8ua6196mc1r7qkfog53rkg0: Rmdir: contains trashed file: "2m507n64kafsi59v9q71r281a4" 2025/04/19 01:54:59 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-feyixep3capu': deleted 3 directories run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-feyixep3capu'", Local "Local file system at /tmp/rclone3509792376", Modify Window "1ms" 2025/04/19 01:55:01 DEBUG : 3i9du405pfogq3ncai6pg7ouio: Rmdir: contains trashed file: "982d3pss7t5pn0il16r2foj31s" 2025/04/19 01:55:02 DEBUG : 2bsvlrk2ne1lfitm6tttcu0qt8: Rmdir: contains trashed file: "89l8renevh3mji1c8r1p7qn6tg" --- PASS: TestSyncAfterRemovingAFileAndAddingAFileSubDir (16.11s) === RUN TestSyncAfterRemovingAFileAndAddingAFileSubDirWithErrors run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-feyixep3capu'", Local "Local file system at /tmp/rclone3509792376", Modify Window "1ms" 2025/04/19 01:55:05 DEBUG : b/potato: md5 = 33ff36f052c4aed00245c0f82f046c5d OK 2025/04/19 01:55:08 DEBUG : c/non empty space: md5 = b3f5e73baed953282a940c2e18f55359 OK 2025/04/19 01:55:08 INFO : d: Making directory 2025/04/19 01:55:09 DEBUG : Added delayed dir = "a", newDst= 2025/04/19 01:55:10 INFO : c: Set directory modification time (using SetModTime) 2025/04/19 01:55:10 DEBUG : Added delayed dir = "c", newDst=c 2025/04/19 01:55:10 DEBUG : c/non empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/04/19 01:55:10 DEBUG : a/potato2: Need to transfer - File not found at Destination 2025/04/19 01:55:10 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-feyixep3capu': Waiting for checks to finish 2025/04/19 01:55:10 DEBUG : c/non empty space: Unchanged skipping 2025/04/19 01:55:10 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-feyixep3capu': Waiting for transfers to finish 2025/04/19 01:55:12 DEBUG : a/potato2: md5 = e552c3a0e23d92f18555e8564421d0f1 OK 2025/04/19 01:55:12 INFO : a/potato2: Copied (new) 2025/04/19 01:55:12 ERROR : Encrypted drive 'TestCryptDrive:rclone-test-feyixep3capu': not deleting files as there were IO errors 2025/04/19 01:55:12 INFO : a: Set directory modification time (using DirSetModTime) 2025/04/19 01:55:12 ERROR : Encrypted drive 'TestCryptDrive:rclone-test-feyixep3capu': not deleting directories as there were IO errors run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-feyixep3capu'", Local "Local file system at /tmp/rclone3509792376", Modify Window "1ms" 2025/04/19 01:55:15 DEBUG : 3i9du405pfogq3ncai6pg7ouio: Rmdir: contains trashed file: "982d3pss7t5pn0il16r2foj31s" 2025/04/19 01:55:16 DEBUG : 32d8ua6196mc1r7qkfog53rkg0: Rmdir: contains trashed file: "2m507n64kafsi59v9q71r281a4" 2025/04/19 01:55:17 DEBUG : 2bsvlrk2ne1lfitm6tttcu0qt8: Rmdir: contains trashed file: "89l8renevh3mji1c8r1p7qn6tg" --- PASS: TestSyncAfterRemovingAFileAndAddingAFileSubDirWithErrors (14.57s) === RUN TestSyncDeleteAfter --- PASS: TestSyncDeleteAfter (0.00s) === RUN TestSyncDeleteDuring run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-feyixep3capu'", Local "Local file system at /tmp/rclone3509792376", Modify Window "1ms" 2025/04/19 01:55:19 DEBUG : potato: md5 = 43d82a5ba8c61ca679ac61ff1eea0d93 OK 2025/04/19 01:55:20 DEBUG : empty space: md5 = b049f3b29b98d2f3158cefbb15fd9247 OK 2025/04/19 01:55:21 DEBUG : Waiting for deletions to finish 2025/04/19 01:55:21 DEBUG : empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/04/19 01:55:21 DEBUG : potato2: Need to transfer - File not found at Destination 2025/04/19 01:55:21 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-feyixep3capu': Waiting for checks to finish 2025/04/19 01:55:21 DEBUG : empty space: Unchanged skipping 2025/04/19 01:55:21 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-feyixep3capu': Waiting for transfers to finish 2025/04/19 01:55:21 INFO : potato: Deleted 2025/04/19 01:55:22 DEBUG : potato2: md5 = ecd8aa6897e4038c4ebdf8bae28cbb48 OK 2025/04/19 01:55:22 INFO : potato2: Copied (new) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-feyixep3capu'", Local "Local file system at /tmp/rclone3509792376", Modify Window "1ms" --- PASS: TestSyncDeleteDuring (6.35s) === RUN TestSyncDeleteBefore run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-feyixep3capu'", Local "Local file system at /tmp/rclone3509792376", Modify Window "1ms" 2025/04/19 01:55:26 DEBUG : potato: md5 = 7790a2dc0215ff44e480a12ddae698a4 OK 2025/04/19 01:55:27 DEBUG : empty space: md5 = c13578e70dfedd66cf2e6149853f0ae2 OK 2025/04/19 01:55:27 DEBUG : Waiting for deletions to finish 2025/04/19 01:55:27 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-feyixep3capu': Waiting for checks to finish 2025/04/19 01:55:27 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-feyixep3capu': Waiting for transfers to finish 2025/04/19 01:55:28 INFO : potato: Deleted 2025/04/19 01:55:28 DEBUG : empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/04/19 01:55:28 DEBUG : potato2: Need to transfer - File not found at Destination 2025/04/19 01:55:28 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-feyixep3capu': Waiting for checks to finish 2025/04/19 01:55:28 DEBUG : empty space: Unchanged skipping 2025/04/19 01:55:28 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-feyixep3capu': Waiting for transfers to finish 2025/04/19 01:55:29 DEBUG : potato2: md5 = 7235280efba715e05dca11504386c63a OK 2025/04/19 01:55:29 INFO : potato2: Copied (new) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-feyixep3capu'", Local "Local file system at /tmp/rclone3509792376", Modify Window "1ms" --- PASS: TestSyncDeleteBefore (7.35s) === RUN TestCopyDeleteBefore run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-feyixep3capu'", Local "Local file system at /tmp/rclone3509792376", Modify Window "1ms" 2025/04/19 01:55:33 DEBUG : potato: md5 = 959d53c57b18b2c5c5ff3478913ad195 OK 2025/04/19 01:55:33 DEBUG : potato2: Need to transfer - File not found at Destination 2025/04/19 01:55:33 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-feyixep3capu': Waiting for checks to finish 2025/04/19 01:55:33 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-feyixep3capu': Waiting for transfers to finish 2025/04/19 01:55:34 DEBUG : potato2: md5 = de62580754f325ed24ef47146ebee813 OK 2025/04/19 01:55:34 INFO : potato2: Copied (new) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-feyixep3capu'", Local "Local file system at /tmp/rclone3509792376", Modify Window "1ms" --- PASS: TestCopyDeleteBefore (4.96s) === RUN TestSyncWithExclude run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-feyixep3capu'", Local "Local file system at /tmp/rclone3509792376", Modify Window "1ms" 2025/04/19 01:55:38 DEBUG : potato2: md5 = 27ce9cffadf990cd1d3be3056954e7cd OK 2025/04/19 01:55:39 DEBUG : empty space: md5 = 2a1f4187985e341808ea41b3443292bd OK 2025/04/19 01:55:39 DEBUG : enormous: Excluded (Size Filter) 2025/04/19 01:55:39 DEBUG : enormous: Excluded 2025/04/19 01:55:39 DEBUG : potato2: Excluded (Size Filter) 2025/04/19 01:55:39 DEBUG : potato2: Excluded 2025/04/19 01:55:39 DEBUG : potato2: Excluded (Size Filter) 2025/04/19 01:55:39 DEBUG : empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/04/19 01:55:39 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-feyixep3capu': Waiting for checks to finish 2025/04/19 01:55:39 DEBUG : empty space: Unchanged skipping 2025/04/19 01:55:39 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-feyixep3capu': Waiting for transfers to finish 2025/04/19 01:55:39 DEBUG : Waiting for deletions to finish 2025/04/19 01:55:39 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-feyixep3capu'", Local "Local file system at /tmp/rclone3509792376", Modify Window "1ms" 2025/04/19 01:55:40 DEBUG : enormous: Excluded (Size Filter) 2025/04/19 01:55:40 DEBUG : enormous: Excluded 2025/04/19 01:55:40 DEBUG : potato2: Excluded (Size Filter) 2025/04/19 01:55:40 DEBUG : potato2: Excluded 2025/04/19 01:55:40 DEBUG : potato2: Excluded (Size Filter) 2025/04/19 01:55:40 DEBUG : Local file system at /tmp/rclone3509792376: Waiting for checks to finish 2025/04/19 01:55:40 DEBUG : empty space: Size and modification time the same (differ by 456.789µs, within tolerance 1ms) 2025/04/19 01:55:40 DEBUG : empty space: Unchanged skipping 2025/04/19 01:55:40 DEBUG : Local file system at /tmp/rclone3509792376: Waiting for transfers to finish 2025/04/19 01:55:40 DEBUG : Waiting for deletions to finish 2025/04/19 01:55:40 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-feyixep3capu'", Local "Local file system at /tmp/rclone3509792376", Modify Window "1ms" --- PASS: TestSyncWithExclude (5.81s) === RUN TestSyncWithExcludeAndDeleteExcluded run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-feyixep3capu'", Local "Local file system at /tmp/rclone3509792376", Modify Window "1ms" 2025/04/19 01:55:44 DEBUG : potato2: md5 = 88874c6762b28a08d5a471ae1565c8e4 OK 2025/04/19 01:55:45 DEBUG : empty space: md5 = 1b87cbfc1075d19b036a10f13f54f316 OK 2025/04/19 01:55:46 DEBUG : enormous: md5 = 627eeedd5d3b45851e2a50f8a3eb3c43 OK 2025/04/19 01:55:46 DEBUG : enormous: Excluded (Size Filter) 2025/04/19 01:55:46 DEBUG : enormous: Excluded 2025/04/19 01:55:46 DEBUG : potato2: Excluded (Size Filter) 2025/04/19 01:55:46 DEBUG : potato2: Excluded 2025/04/19 01:55:47 DEBUG : empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/04/19 01:55:47 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-feyixep3capu': Waiting for checks to finish 2025/04/19 01:55:47 DEBUG : empty space: Unchanged skipping 2025/04/19 01:55:47 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-feyixep3capu': Waiting for transfers to finish 2025/04/19 01:55:47 DEBUG : Waiting for deletions to finish 2025/04/19 01:55:47 INFO : enormous: Deleted 2025/04/19 01:55:47 INFO : potato2: Deleted 2025/04/19 01:55:47 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-feyixep3capu'", Local "Local file system at /tmp/rclone3509792376", Modify Window "1ms" 2025/04/19 01:55:48 DEBUG : empty space: Size and modification time the same (differ by 456.789µs, within tolerance 1ms) 2025/04/19 01:55:48 DEBUG : empty space: Unchanged skipping 2025/04/19 01:55:48 DEBUG : Local file system at /tmp/rclone3509792376: Waiting for checks to finish 2025/04/19 01:55:48 DEBUG : Local file system at /tmp/rclone3509792376: Waiting for transfers to finish 2025/04/19 01:55:48 DEBUG : Waiting for deletions to finish 2025/04/19 01:55:48 INFO : enormous: Deleted 2025/04/19 01:55:48 INFO : potato2: Deleted 2025/04/19 01:55:48 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-feyixep3capu'", Local "Local file system at /tmp/rclone3509792376", Modify Window "1ms" --- PASS: TestSyncWithExcludeAndDeleteExcluded (7.16s) === RUN TestSyncWithUpdateOlder run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-feyixep3capu'", Local "Local file system at /tmp/rclone3509792376", Modify Window "1ms" 2025/04/19 01:55:51 DEBUG : one: md5 = 1a4dc6ca74acd9ded4fa985eb8a38190 OK 2025/04/19 01:55:52 DEBUG : two: md5 = ddfe52b362c19ab9ee97b85fab46d9d7 OK 2025/04/19 01:55:53 DEBUG : three: md5 = 84edd3c7f45ca4501c1de3177918eb9f OK 2025/04/19 01:55:55 DEBUG : four: md5 = cc95304f55b532028cc3f0d9d136ffda OK 2025/04/19 01:55:55 DEBUG : five: Need to transfer - File not found at Destination 2025/04/19 01:55:55 DEBUG : four: Sizes differ (src 4 vs dst 8) 2025/04/19 01:55:55 DEBUG : one: Destination is newer than source, skipping 2025/04/19 01:55:55 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-feyixep3capu': Waiting for checks to finish 2025/04/19 01:55:55 DEBUG : three: Sizes identical 2025/04/19 01:55:55 DEBUG : four: Destination mod time is within 1s of source but files differ, transferring 2025/04/19 01:55:55 DEBUG : three: Destination mod time is within 1s of source and files identical, skipping 2025/04/19 01:55:55 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-feyixep3capu': Waiting for transfers to finish 2025/04/19 01:55:56 DEBUG : two: md5 = e40f073e838d6c81c0be82680cfbe91b OK 2025/04/19 01:55:56 INFO : two: Copied (replaced existing) 2025/04/19 01:55:56 DEBUG : five: md5 = 84ed449f807f85f66cf1427536ec2013 OK 2025/04/19 01:55:56 INFO : five: Copied (new) 2025/04/19 01:55:56 DEBUG : four: md5 = 71e8751c1805edaa0ddf344b365d2e21 OK 2025/04/19 01:55:56 INFO : four: Copied (replaced existing) 2025/04/19 01:55:56 DEBUG : Waiting for deletions to finish sync_test.go:1449: Skip test with --checksum as no hashes supported --- PASS: TestSyncWithUpdateOlder (9.86s) === 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-feyixep3capu'", Local "Local file system at /tmp/rclone3509792376", Modify Window "1ms" sync_test.go:1538: Can track renames: false 2025/04/19 01:55:59 ERROR : Encrypted drive 'TestCryptDrive:rclone-test-feyixep3capu': Ignoring --track-renames as the source and destination do not have a common hash 2025/04/19 01:55:59 DEBUG : potato: Need to transfer - File not found at Destination 2025/04/19 01:55:59 DEBUG : yam: Need to transfer - File not found at Destination 2025/04/19 01:55:59 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-feyixep3capu': Waiting for checks to finish 2025/04/19 01:55:59 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-feyixep3capu': Waiting for transfers to finish 2025/04/19 01:56:01 DEBUG : yam: md5 = 4801a63ca222b20e430e2ac7062d1571 OK 2025/04/19 01:56:01 INFO : yam: Copied (new) 2025/04/19 01:56:01 DEBUG : potato: md5 = ae06049422504fa571d9c9c9d429fcb4 OK 2025/04/19 01:56:01 INFO : potato: Copied (new) 2025/04/19 01:56:01 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-feyixep3capu'", Local "Local file system at /tmp/rclone3509792376", Modify Window "1ms" 2025/04/19 01:56:01 ERROR : Encrypted drive 'TestCryptDrive:rclone-test-feyixep3capu': Ignoring --track-renames as the source and destination do not have a common hash 2025/04/19 01:56:01 DEBUG : potato: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/19 01:56:01 DEBUG : yaml: Need to transfer - File not found at Destination 2025/04/19 01:56:01 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-feyixep3capu': Waiting for checks to finish 2025/04/19 01:56:01 DEBUG : potato: Unchanged skipping 2025/04/19 01:56:01 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-feyixep3capu': Waiting for transfers to finish 2025/04/19 01:56:03 DEBUG : yaml: md5 = 4a623c69171a9dfbcdc9bc4afb0b600a OK 2025/04/19 01:56:03 INFO : yaml: Copied (new) 2025/04/19 01:56:03 DEBUG : Waiting for deletions to finish 2025/04/19 01:56:03 INFO : yam: Deleted run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-feyixep3capu'", Local "Local file system at /tmp/rclone3509792376", Modify Window "1ms" --- PASS: TestSyncWithTrackRenames (6.13s) === RUN TestParseRenamesStrategyModtime --- PASS: TestParseRenamesStrategyModtime (0.00s) === RUN TestRenamesStrategyModtime --- PASS: TestRenamesStrategyModtime (0.00s) === RUN TestSyncWithTrackRenamesStrategyModtime run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-feyixep3capu'", Local "Local file system at /tmp/rclone3509792376", Modify Window "1ms" sync_test.go:1610: Can track renames: true 2025/04/19 01:56:06 INFO : Encrypted drive 'TestCryptDrive:rclone-test-feyixep3capu': Making map for --track-renames 2025/04/19 01:56:06 INFO : Encrypted drive 'TestCryptDrive:rclone-test-feyixep3capu': Finished making map for --track-renames 2025/04/19 01:56:06 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-feyixep3capu': Waiting for checks to finish 2025/04/19 01:56:06 DEBUG : potato: Need to transfer - No matching file found at Destination 2025/04/19 01:56:06 DEBUG : yam: Need to transfer - No matching file found at Destination 2025/04/19 01:56:06 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-feyixep3capu': Waiting for renames to finish 2025/04/19 01:56:06 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-feyixep3capu': Waiting for transfers to finish 2025/04/19 01:56:07 DEBUG : potato: md5 = 1674b87f19d74fb1d8d8474fa583df5b OK 2025/04/19 01:56:07 INFO : potato: Copied (new) 2025/04/19 01:56:07 DEBUG : yam: md5 = 1de2acca50efc6226a2ac92b40a188a4 OK 2025/04/19 01:56:07 INFO : yam: Copied (new) 2025/04/19 01:56:07 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-feyixep3capu'", Local "Local file system at /tmp/rclone3509792376", Modify Window "1ms" 2025/04/19 01:56:08 DEBUG : potato: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/19 01:56:08 INFO : Encrypted drive 'TestCryptDrive:rclone-test-feyixep3capu': Making map for --track-renames 2025/04/19 01:56:08 INFO : Encrypted drive 'TestCryptDrive:rclone-test-feyixep3capu': Finished making map for --track-renames 2025/04/19 01:56:08 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-feyixep3capu': Waiting for checks to finish 2025/04/19 01:56:08 DEBUG : potato: Unchanged skipping 2025/04/19 01:56:08 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-feyixep3capu': Waiting for renames to finish 2025/04/19 01:56:08 INFO : yam: Moved (server-side) to: yaml 2025/04/19 01:56:08 INFO : yaml: Renamed from "yam" 2025/04/19 01:56:08 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-feyixep3capu': Waiting for transfers to finish 2025/04/19 01:56:08 DEBUG : Waiting for deletions to finish 2025/04/19 01:56:08 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-feyixep3capu'", Local "Local file system at /tmp/rclone3509792376", Modify Window "1ms" --- PASS: TestSyncWithTrackRenamesStrategyModtime (5.36s) === RUN TestSyncWithTrackRenamesStrategyLeaf run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-feyixep3capu'", Local "Local file system at /tmp/rclone3509792376", Modify Window "1ms" sync_test.go:1649: Can track renames: true 2025/04/19 01:56:11 DEBUG : Added delayed dir = "sub", newDst= 2025/04/19 01:56:11 INFO : Encrypted drive 'TestCryptDrive:rclone-test-feyixep3capu': Making map for --track-renames 2025/04/19 01:56:11 INFO : Encrypted drive 'TestCryptDrive:rclone-test-feyixep3capu': Finished making map for --track-renames 2025/04/19 01:56:11 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-feyixep3capu': Waiting for checks to finish 2025/04/19 01:56:11 DEBUG : potato: Need to transfer - No matching file found at Destination 2025/04/19 01:56:11 DEBUG : sub/yam: Need to transfer - No matching file found at Destination 2025/04/19 01:56:11 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-feyixep3capu': Waiting for renames to finish 2025/04/19 01:56:11 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-feyixep3capu': Waiting for transfers to finish 2025/04/19 01:56:13 DEBUG : sub/yam: md5 = 899fcbc8b51e9ab57942e0600ac93faf OK 2025/04/19 01:56:13 INFO : sub/yam: Copied (new) 2025/04/19 01:56:13 DEBUG : potato: md5 = 0540408548e5198b27fb6de292e51196 OK 2025/04/19 01:56:13 INFO : potato: Copied (new) 2025/04/19 01:56:13 DEBUG : Waiting for deletions to finish 2025/04/19 01:56:13 INFO : sub: Set directory modification time (using DirSetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-feyixep3capu'", Local "Local file system at /tmp/rclone3509792376", Modify Window "1ms" 2025/04/19 01:56:14 DEBUG : potato: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/19 01:56:14 DEBUG : potato: Unchanged skipping 2025/04/19 01:56:15 INFO : sub: Set directory modification time (using SetModTime) 2025/04/19 01:56:15 DEBUG : Added delayed dir = "sub", newDst=sub 2025/04/19 01:56:15 INFO : Encrypted drive 'TestCryptDrive:rclone-test-feyixep3capu': Making map for --track-renames 2025/04/19 01:56:15 INFO : Encrypted drive 'TestCryptDrive:rclone-test-feyixep3capu': Finished making map for --track-renames 2025/04/19 01:56:15 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-feyixep3capu': Waiting for checks to finish 2025/04/19 01:56:15 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-feyixep3capu': Waiting for renames to finish 2025/04/19 01:56:16 INFO : sub/yam: Moved (server-side) to: yam 2025/04/19 01:56:16 INFO : yam: Renamed from "sub/yam" 2025/04/19 01:56:16 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-feyixep3capu': Waiting for transfers to finish 2025/04/19 01:56:16 DEBUG : Waiting for deletions to finish 2025/04/19 01:56:16 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-feyixep3capu'", Local "Local file system at /tmp/rclone3509792376", Modify Window "1ms" --- PASS: TestSyncWithTrackRenamesStrategyLeaf (8.52s) === RUN TestServerSideMoveLocal run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-feyixep3capu'", Local "Local file system at /tmp/rclone3509792376", Modify Window "1ms" 2025/04/19 01:56:19 DEBUG : Creating backend with remote "/tmp/rclone3509792376/dir1" 2025/04/19 01:56:19 DEBUG : Creating backend with remote "/tmp/rclone3509792376/dir2" 2025/04/19 01:56:19 DEBUG : Local file system at /tmp/rclone3509792376/dir2: Using server-side directory move 2025/04/19 01:56:19 INFO : Local file system at /tmp/rclone3509792376/dir2: Server side directory move failed - fallback to file moves: can't copy directory - destination already exists 2025/04/19 01:56:19 DEBUG : file1.txt: Need to transfer - File not found at Destination 2025/04/19 01:56:19 DEBUG : Local file system at /tmp/rclone3509792376/dir2: Waiting for checks to finish 2025/04/19 01:56:19 INFO : file1.txt: Moved (server-side) 2025/04/19 01:56:19 DEBUG : Local file system at /tmp/rclone3509792376/dir2: Waiting for transfers to finish --- PASS: TestServerSideMoveLocal (0.45s) === RUN TestMoveWithDeleteEmptySrcDirs run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-feyixep3capu'", Local "Local file system at /tmp/rclone3509792376", Modify Window "1ms" 2025/04/19 01:56:20 DEBUG : Added delayed dir = "nested", newDst= 2025/04/19 01:56:20 DEBUG : Added delayed dir = "sub dir", newDst= 2025/04/19 01:56:20 DEBUG : Added delayed dir = "nested/sub dir", newDst= 2025/04/19 01:56:20 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2025/04/19 01:56:20 DEBUG : nested/sub dir/file: Need to transfer - File not found at Destination 2025/04/19 01:56:20 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-feyixep3capu': Waiting for checks to finish 2025/04/19 01:56:20 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-feyixep3capu': Waiting for transfers to finish 2025/04/19 01:56:22 DEBUG : sub dir/hello world: md5 = 356d99738331a8fdd14ecc2a9fbf9899 OK 2025/04/19 01:56:22 INFO : sub dir/hello world: Copied (new) 2025/04/19 01:56:22 INFO : sub dir/hello world: Deleted 2025/04/19 01:56:24 DEBUG : nested/sub dir/file: md5 = c623e08cf98f8b0101732c910a7eefb7 OK 2025/04/19 01:56:24 INFO : nested/sub dir/file: Copied (new) 2025/04/19 01:56:24 INFO : nested/sub dir/file: Deleted 2025/04/19 01:56:24 INFO : nested/sub dir: Set directory modification time (using DirSetModTime) 2025/04/19 01:56:25 INFO : nested: Set directory modification time (using DirSetModTime) 2025/04/19 01:56:25 INFO : sub dir: Set directory modification time (using DirSetModTime) 2025/04/19 01:56:25 INFO : sub dir: Removing directory 2025/04/19 01:56:25 INFO : nested/sub dir: Removing directory 2025/04/19 01:56:25 INFO : nested: Removing directory 2025/04/19 01:56:25 DEBUG : Local file system at /tmp/rclone3509792376: deleted 3 directories run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-feyixep3capu'", Local "Local file system at /tmp/rclone3509792376", Modify Window "1ms" 2025/04/19 01:56:27 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" 2025/04/19 01:56:28 DEBUG : 37qp6d1gohacv723ij3brofbu8/14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "ftp4kuv8se7tqduu6pmmcvjsmk" 2025/04/19 01:56:29 DEBUG : 37qp6d1gohacv723ij3brofbu8: Rmdir: contains trashed file: "14begaa36ih249fgrnfk6nulg0" --- PASS: TestMoveWithDeleteEmptySrcDirs (9.94s) === RUN TestMoveWithoutDeleteEmptySrcDirs run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-feyixep3capu'", Local "Local file system at /tmp/rclone3509792376", Modify Window "1ms" 2025/04/19 01:56:30 DEBUG : Added delayed dir = "nested", newDst= 2025/04/19 01:56:30 DEBUG : Added delayed dir = "sub dir", newDst= 2025/04/19 01:56:30 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2025/04/19 01:56:30 DEBUG : Added delayed dir = "nested/sub dir", newDst= 2025/04/19 01:56:30 DEBUG : nested/sub dir/file: Need to transfer - File not found at Destination 2025/04/19 01:56:30 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-feyixep3capu': Waiting for checks to finish 2025/04/19 01:56:30 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-feyixep3capu': Waiting for transfers to finish 2025/04/19 01:56:32 DEBUG : sub dir/hello world: md5 = 6ef8c7697e5cc7b56bb0e01e070e86f1 OK 2025/04/19 01:56:32 INFO : sub dir/hello world: Copied (new) 2025/04/19 01:56:32 INFO : sub dir/hello world: Deleted 2025/04/19 01:56:34 DEBUG : nested/sub dir/file: md5 = 19ab1f281f30bf991580a8d7f0a62621 OK 2025/04/19 01:56:34 INFO : nested/sub dir/file: Copied (new) 2025/04/19 01:56:34 INFO : nested/sub dir/file: Deleted 2025/04/19 01:56:34 INFO : nested/sub dir: Set directory modification time (using DirSetModTime) 2025/04/19 01:56:35 INFO : nested: Set directory modification time (using DirSetModTime) 2025/04/19 01:56:35 INFO : sub dir: Set directory modification time (using DirSetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-feyixep3capu'", Local "Local file system at /tmp/rclone3509792376", Modify Window "1ms" 2025/04/19 01:56:37 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" 2025/04/19 01:56:38 DEBUG : 37qp6d1gohacv723ij3brofbu8/14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "ftp4kuv8se7tqduu6pmmcvjsmk" 2025/04/19 01:56:39 DEBUG : 37qp6d1gohacv723ij3brofbu8: Rmdir: contains trashed file: "14begaa36ih249fgrnfk6nulg0" --- PASS: TestMoveWithoutDeleteEmptySrcDirs (10.08s) === RUN TestMoveWithIgnoreExisting run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-feyixep3capu'", Local "Local file system at /tmp/rclone3509792376", Modify Window "1ms" 2025/04/19 01:56:40 DEBUG : existing: Need to transfer - File not found at Destination 2025/04/19 01:56:40 DEBUG : existing-b: Need to transfer - File not found at Destination 2025/04/19 01:56:40 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-feyixep3capu': Waiting for checks to finish 2025/04/19 01:56:40 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-feyixep3capu': Waiting for transfers to finish 2025/04/19 01:56:41 DEBUG : existing-b: md5 = c62306411f6cf506112084a4c713139b OK 2025/04/19 01:56:41 INFO : existing-b: Copied (new) 2025/04/19 01:56:41 INFO : existing-b: Deleted 2025/04/19 01:56:41 DEBUG : existing: md5 = b46c96fe8c8dce089f3433fab04c1eb1 OK 2025/04/19 01:56:41 INFO : existing: Copied (new) 2025/04/19 01:56:41 INFO : existing: Deleted 2025/04/19 01:56:42 DEBUG : existing: Destination exists, skipping 2025/04/19 01:56:42 DEBUG : existing: Not removing source file as destination file exists and --ignore-existing is set 2025/04/19 01:56:42 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-feyixep3capu': Waiting for checks to finish 2025/04/19 01:56:42 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-feyixep3capu': Waiting for transfers to finish 2025/04/19 01:56:42 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-feyixep3capu'", Local "Local file system at /tmp/rclone3509792376", Modify Window "1ms" --- PASS: TestMoveWithIgnoreExisting (5.31s) === RUN TestServerSideMove run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-feyixep3capu'", Local "Local file system at /tmp/rclone3509792376", Modify Window "1ms" 2025/04/19 01:56:45 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-vazudel3mige" 2025/04/19 01:56:45 DEBUG : Creating backend with remote "TestDrive:crypt/djkbvpq6j860o4bpefngnb88usec8murpitkobsi8qiqagc7m6b0" 2025/04/19 01:56:47 DEBUG : potato2: md5 = 0ddd494aebfd202b9f753d0901b7b2e2 OK 2025/04/19 01:56:49 DEBUG : empty space: md5 = 915f6cc2719cb4b3279b3b190b6a79fb OK 2025/04/19 01:56:50 DEBUG : potato3: md5 = 8d7554ad7544046c66c56818b117bdb1 OK sync_test.go:1705: Server side move (if possible) Encrypted drive 'TestCryptDrive:rclone-test-feyixep3capu' -> Encrypted drive 'TestCryptDrive:rclone-test-vazudel3mige' 2025/04/19 01:56:52 DEBUG : empty space: md5 = c38b1720fe9b4fbf9f323787321e5e69 OK 2025/04/19 01:56:54 DEBUG : potato3: md5 = 535126aac141774b87550a8ef40bf3e5 OK 2025/04/19 01:56:54 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vazudel3mige': Using server-side directory move 2025/04/19 01:56:54 INFO : Encrypted drive 'TestCryptDrive:rclone-test-vazudel3mige': Server side directory move failed - fallback to file moves: can't copy directory - destination already exists 2025/04/19 01:56:54 DEBUG : potato2: Need to transfer - File not found at Destination 2025/04/19 01:56:54 DEBUG : empty space: Size and modification time the same (differ by 0s, within tolerance 1ms) 2025/04/19 01:56:54 DEBUG : empty space: Unchanged skipping 2025/04/19 01:56:54 DEBUG : potato3: Sizes differ (src 68 vs dst 60) 2025/04/19 01:56:54 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vazudel3mige': Waiting for checks to finish 2025/04/19 01:56:55 INFO : empty space: Deleted 2025/04/19 01:56:55 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vazudel3mige': Waiting for transfers to finish 2025/04/19 01:56:55 INFO : potato3: Deleted 2025/04/19 01:56:55 INFO : potato2: Moved (server-side) 2025/04/19 01:56:55 INFO : potato3: Moved (server-side) 2025/04/19 01:56:56 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-posokaf3bese" 2025/04/19 01:56:56 DEBUG : Creating backend with remote "TestDrive:crypt/1jtku7qhdfoqq8ebodppmh91goi2dp3avfb3kc1bp8buipgvh8gg" 2025/04/19 01:56:57 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-posokaf3bese': Using server-side directory move 2025/04/19 01:56:57 INFO : Encrypted drive 'TestCryptDrive:rclone-test-posokaf3bese': Server side directory move succeeded 2025/04/19 01:56:58 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-posokaf3bese': Purge remote 2025/04/19 01:56:59 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vazudel3mige': Purge remote 2025/04/19 01:56:59 NOTICE: purge failed: directory not found --- PASS: TestServerSideMove (14.17s) === RUN TestServerSideMoveWithFilter run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-feyixep3capu'", Local "Local file system at /tmp/rclone3509792376", Modify Window "1ms" 2025/04/19 01:56:59 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-gesawij1puge" 2025/04/19 01:56:59 DEBUG : Creating backend with remote "TestDrive:crypt/igh444a1rp0l2535ncvibqkrrspi8rks1jsega0s1ccp99vopv8g" 2025/04/19 01:57:02 DEBUG : potato2: md5 = e784946eae91eb59313ece2fbd0649f4 OK 2025/04/19 01:57:03 DEBUG : empty space: md5 = 5808c0fcad5dad4fa6a68be196442473 OK 2025/04/19 01:57:04 DEBUG : potato3: md5 = 8249b1bf4370b7d5f81ded9ec8fc541a OK sync_test.go:1705: Server side move (if possible) Encrypted drive 'TestCryptDrive:rclone-test-feyixep3capu' -> Encrypted drive 'TestCryptDrive:rclone-test-gesawij1puge' 2025/04/19 01:57:06 DEBUG : empty space: md5 = 4f40cada61fd5dc9b8041cceb1bca2cf OK 2025/04/19 01:57:08 DEBUG : potato3: md5 = 36a28088171d701512807fab0282804e OK 2025/04/19 01:57:08 DEBUG : empty space: Excluded (Size Filter) 2025/04/19 01:57:08 DEBUG : empty space: Excluded (Size Filter) 2025/04/19 01:57:08 DEBUG : potato2: Need to transfer - File not found at Destination 2025/04/19 01:57:08 DEBUG : potato3: Sizes differ (src 68 vs dst 60) 2025/04/19 01:57:08 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gesawij1puge': Waiting for checks to finish 2025/04/19 01:57:08 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gesawij1puge': Waiting for transfers to finish 2025/04/19 01:57:09 INFO : potato3: Deleted 2025/04/19 01:57:09 INFO : potato2: Moved (server-side) 2025/04/19 01:57:09 INFO : potato3: Moved (server-side) 2025/04/19 01:57:10 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-sodiwih2ceyo" 2025/04/19 01:57:10 DEBUG : Creating backend with remote "TestDrive:crypt/lntbs5qt4jsotgljnfjolpsojhqb69b9158ra2g4j607o6jlppdg" 2025/04/19 01:57:11 DEBUG : empty space: Excluded (Size Filter) 2025/04/19 01:57:11 DEBUG : potato2: Need to transfer - File not found at Destination 2025/04/19 01:57:11 DEBUG : potato3: Need to transfer - File not found at Destination 2025/04/19 01:57:11 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-sodiwih2ceyo': Waiting for checks to finish 2025/04/19 01:57:11 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-sodiwih2ceyo': Waiting for transfers to finish 2025/04/19 01:57:12 INFO : potato3: Moved (server-side) 2025/04/19 01:57:13 INFO : potato2: Moved (server-side) 2025/04/19 01:57:13 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-sodiwih2ceyo': Purge remote 2025/04/19 01:57:13 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gesawij1puge': Purge remote --- PASS: TestServerSideMoveWithFilter (15.56s) === RUN TestServerSideMoveDeleteEmptySourceDirs run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-feyixep3capu'", Local "Local file system at /tmp/rclone3509792376", Modify Window "1ms" 2025/04/19 01:57:15 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-komutuc7nufo" 2025/04/19 01:57:15 DEBUG : Creating backend with remote "TestDrive:crypt/riksn4pqnlmp8jctdtbh6h93ar5rdcgvc2fp5i3ud956sg697gn0" 2025/04/19 01:57:17 DEBUG : potato2: md5 = 4afa286e44616d3d17bae461f3e8e739 OK 2025/04/19 01:57:19 DEBUG : empty space: md5 = 64d6f2855c0b61c7e3711d54154dbcb0 OK 2025/04/19 01:57:20 DEBUG : potato3: md5 = ff0d505a2c24b4851a63897205da24a2 OK 2025/04/19 01:57:20 INFO : tomatoDir: Making directory sync_test.go:1705: Server side move (if possible) Encrypted drive 'TestCryptDrive:rclone-test-feyixep3capu' -> Encrypted drive 'TestCryptDrive:rclone-test-komutuc7nufo' 2025/04/19 01:57:23 DEBUG : empty space: md5 = 1dce3b8fac0099fe9fe53e1932c23ac0 OK 2025/04/19 01:57:24 DEBUG : potato3: md5 = f110b032f88ecdc9225f8fdc91ce1c10 OK 2025/04/19 01:57:25 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-komutuc7nufo': Using server-side directory move 2025/04/19 01:57:25 INFO : Encrypted drive 'TestCryptDrive:rclone-test-komutuc7nufo': Server side directory move failed - fallback to file moves: can't copy directory - destination already exists 2025/04/19 01:57:25 DEBUG : potato2: Need to transfer - File not found at Destination 2025/04/19 01:57:25 DEBUG : Added delayed dir = "tomatoDir", newDst= 2025/04/19 01:57:25 DEBUG : empty space: Size and modification time the same (differ by 0s, within tolerance 1ms) 2025/04/19 01:57:25 DEBUG : empty space: Unchanged skipping 2025/04/19 01:57:25 DEBUG : potato3: Sizes differ (src 68 vs dst 60) 2025/04/19 01:57:25 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-komutuc7nufo': Waiting for checks to finish 2025/04/19 01:57:26 INFO : empty space: Deleted 2025/04/19 01:57:26 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-komutuc7nufo': Waiting for transfers to finish 2025/04/19 01:57:26 INFO : potato3: Deleted 2025/04/19 01:57:26 INFO : potato2: Moved (server-side) 2025/04/19 01:57:26 INFO : potato3: Moved (server-side) 2025/04/19 01:57:26 INFO : tomatoDir: Removing directory 2025/04/19 01:57:27 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-feyixep3capu': deleted 1 directories 2025/04/19 01:57:27 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-pihinub7jaku" 2025/04/19 01:57:28 DEBUG : Creating backend with remote "TestDrive:crypt/36g3mirfebtup3n0olf3o1sjblqela213km3id1599tiplhr4ugg" 2025/04/19 01:57:28 INFO : tomatoDir: Making directory 2025/04/19 01:57:29 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pihinub7jaku': Using server-side directory move 2025/04/19 01:57:30 INFO : Encrypted drive 'TestCryptDrive:rclone-test-pihinub7jaku': Server side directory move succeeded 2025/04/19 01:57:31 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pihinub7jaku': Purge remote 2025/04/19 01:57:32 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-komutuc7nufo': Purge remote 2025/04/19 01:57:32 NOTICE: purge failed: directory not found --- PASS: TestServerSideMoveDeleteEmptySourceDirs (17.53s) === RUN TestServerSideMoveOverlap run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-feyixep3capu'", Local "Local file system at /tmp/rclone3509792376", Modify Window "1ms" sync_test.go:1910: Skipping test as remote supports DirMove --- SKIP: TestServerSideMoveOverlap (0.44s) === RUN TestSyncOverlap run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-feyixep3capu'", Local "Local file system at /tmp/rclone3509792376", Modify Window "1ms" 2025/04/19 01:57:33 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-feyixep3capu/rclone-sync-test" 2025/04/19 01:57:33 DEBUG : Creating backend with remote "TestDrive:crypt/iktac5oqe17khgjvgdp5oj3naolfecsltrdlansb2vpgjtapv0j0/i7355aa0sb89uagn75vfjqr6s3e3e1h2et8in57abn1fe8qfego0" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-feyixep3capu'", Local "Local file system at /tmp/rclone3509792376", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-feyixep3capu'", Local "Local file system at /tmp/rclone3509792376", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-feyixep3capu'", Local "Local file system at /tmp/rclone3509792376", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-feyixep3capu'", Local "Local file system at /tmp/rclone3509792376", Modify Window "1ms" --- PASS: TestSyncOverlap (3.51s) === RUN TestSyncOverlapWithFilter run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-feyixep3capu'", Local "Local file system at /tmp/rclone3509792376", Modify Window "1ms" 2025/04/19 01:57:36 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-feyixep3capu/rclone-sync-test" 2025/04/19 01:57:36 DEBUG : Creating backend with remote "TestDrive:crypt/iktac5oqe17khgjvgdp5oj3naolfecsltrdlansb2vpgjtapv0j0/i7355aa0sb89uagn75vfjqr6s3e3e1h2et8in57abn1fe8qfego0" 2025/04/19 01:57:38 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-feyixep3capu/rclone-sync-test-include/layer2" 2025/04/19 01:57:38 DEBUG : Creating backend with remote "TestDrive:crypt/iktac5oqe17khgjvgdp5oj3naolfecsltrdlansb2vpgjtapv0j0/khf2vlblvnbf9ftevqm0htmss73hj1j5a7q328e4ohrgs7e2loe0/n01jpl9202nn9ec1rb75h0f1c4" 2025/04/19 01:57:41 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-feyixep3capu/rclone-sync-test-ignore-file" 2025/04/19 01:57:41 DEBUG : Creating backend with remote "TestDrive:crypt/iktac5oqe17khgjvgdp5oj3naolfecsltrdlansb2vpgjtapv0j0/kmf11jujl9uha3tjganvgpkn45bu778hb5vb5riug1c26b38k7sg" 2025/04/19 01:57:45 DEBUG : rclone-sync-test-ignore-file/.ignore: md5 = 9bfc9a54013af8d0df90d643d35087b4 OK 2025/04/19 01:57:47 DEBUG : Added delayed dir = "rclone-sync-test-include", newDst= 2025/04/19 01:57:47 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-feyixep3capu/rclone-sync-test': Waiting for checks to finish 2025/04/19 01:57:47 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-feyixep3capu/rclone-sync-test': Waiting for transfers to finish 2025/04/19 01:57:47 DEBUG : Waiting for deletions to finish 2025/04/19 01:57:47 INFO : There was nothing to transfer 2025/04/19 01:57:49 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-feyixep3capu': Waiting for checks to finish 2025/04/19 01:57:49 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-feyixep3capu': Waiting for transfers to finish 2025/04/19 01:57:49 DEBUG : Waiting for deletions to finish 2025/04/19 01:57:49 INFO : rclone-sync-test-include: Removing directory 2025/04/19 01:57:49 DEBUG : khf2vlblvnbf9ftevqm0htmss73hj1j5a7q328e4ohrgs7e2loe0: Rmdir: contains file: "n01jpl9202nn9ec1rb75h0f1c4" 2025/04/19 01:57:49 DEBUG : rclone-sync-test-include: Failed to Rmdir: directory not empty 2025/04/19 01:57:49 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-feyixep3capu': failed to delete 1 directories 2025/04/19 01:57:49 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-feyixep3capu'", Local "Local file system at /tmp/rclone3509792376", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-feyixep3capu'", Local "Local file system at /tmp/rclone3509792376", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-feyixep3capu'", Local "Local file system at /tmp/rclone3509792376", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-feyixep3capu'", Local "Local file system at /tmp/rclone3509792376", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-feyixep3capu'", Local "Local file system at /tmp/rclone3509792376", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-feyixep3capu'", Local "Local file system at /tmp/rclone3509792376", Modify Window "1ms" 2025/04/19 01:57:51 DEBUG : Added delayed dir = "rclone-sync-test-include", newDst= 2025/04/19 01:57:51 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-feyixep3capu/rclone-sync-test-include/layer2': Waiting for checks to finish 2025/04/19 01:57:51 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-feyixep3capu/rclone-sync-test-include/layer2': Waiting for transfers to finish 2025/04/19 01:57:51 DEBUG : Waiting for deletions to finish 2025/04/19 01:57:51 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-feyixep3capu'", Local "Local file system at /tmp/rclone3509792376", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-feyixep3capu'", Local "Local file system at /tmp/rclone3509792376", Modify Window "1ms" 2025/04/19 01:57:52 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-feyixep3capu': Waiting for checks to finish 2025/04/19 01:57:52 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-feyixep3capu': Waiting for transfers to finish 2025/04/19 01:57:52 DEBUG : Waiting for deletions to finish 2025/04/19 01:57:52 INFO : rclone-sync-test-include: Removing directory 2025/04/19 01:57:53 DEBUG : khf2vlblvnbf9ftevqm0htmss73hj1j5a7q328e4ohrgs7e2loe0: Rmdir: contains file: "n01jpl9202nn9ec1rb75h0f1c4" 2025/04/19 01:57:53 DEBUG : rclone-sync-test-include: Failed to Rmdir: directory not empty 2025/04/19 01:57:53 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-feyixep3capu': failed to delete 1 directories 2025/04/19 01:57:53 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-feyixep3capu'", Local "Local file system at /tmp/rclone3509792376", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-feyixep3capu'", Local "Local file system at /tmp/rclone3509792376", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-feyixep3capu'", Local "Local file system at /tmp/rclone3509792376", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-feyixep3capu'", Local "Local file system at /tmp/rclone3509792376", Modify Window "1ms" 2025/04/19 01:57:54 DEBUG : Added delayed dir = "rclone-sync-test-include", newDst= 2025/04/19 01:57:54 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-feyixep3capu/rclone-sync-test-ignore-file': Waiting for checks to finish 2025/04/19 01:57:54 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-feyixep3capu/rclone-sync-test-ignore-file': Waiting for transfers to finish 2025/04/19 01:57:54 DEBUG : Waiting for deletions to finish 2025/04/19 01:57:54 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-feyixep3capu'", Local "Local file system at /tmp/rclone3509792376", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-feyixep3capu'", Local "Local file system at /tmp/rclone3509792376", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-feyixep3capu'", Local "Local file system at /tmp/rclone3509792376", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-feyixep3capu'", Local "Local file system at /tmp/rclone3509792376", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-feyixep3capu'", Local "Local file system at /tmp/rclone3509792376", Modify Window "1ms" 2025/04/19 01:57:56 DEBUG : khf2vlblvnbf9ftevqm0htmss73hj1j5a7q328e4ohrgs7e2loe0: Rmdir: contains trashed file: "n01jpl9202nn9ec1rb75h0f1c4" 2025/04/19 01:57:57 DEBUG : kmf11jujl9uha3tjganvgpkn45bu778hb5vb5riug1c26b38k7sg: Rmdir: contains trashed file: "i0t74httmdlljg425j6tg570d8" --- PASS: TestSyncOverlapWithFilter (29.34s) === RUN TestSyncCompareDest run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-feyixep3capu'", Local "Local file system at /tmp/rclone3509792376", Modify Window "1ms" 2025/04/19 01:58:06 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-feyixep3capu/dst" 2025/04/19 01:58:06 DEBUG : Creating backend with remote "TestDrive:crypt/iktac5oqe17khgjvgdp5oj3naolfecsltrdlansb2vpgjtapv0j0/31u3jie661vd5p8j7rtc3hgbh0" 2025/04/19 01:58:07 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-feyixep3capu/CompareDest" 2025/04/19 01:58:07 DEBUG : Creating backend with remote "TestDrive:crypt/iktac5oqe17khgjvgdp5oj3naolfecsltrdlansb2vpgjtapv0j0/gveqi14airsml4bgu7krj116o8" 2025/04/19 01:58:09 DEBUG : one: Need to transfer - File not found at Destination 2025/04/19 01:58:09 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-feyixep3capu/dst': Waiting for checks to finish 2025/04/19 01:58:09 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-feyixep3capu/dst': Waiting for transfers to finish 2025/04/19 01:58:11 DEBUG : one: md5 = 62cb1ab1c1308e25f5ed09dcfeea61ae OK 2025/04/19 01:58:11 INFO : one: Copied (new) 2025/04/19 01:58:11 DEBUG : Waiting for deletions to finish 2025/04/19 01:58:12 DEBUG : one: Sizes differ (src 5 vs dst 3) 2025/04/19 01:58:12 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-feyixep3capu/dst': Waiting for checks to finish 2025/04/19 01:58:12 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-feyixep3capu/dst': Waiting for transfers to finish 2025/04/19 01:58:14 DEBUG : one: md5 = 298d236720e396663a1b680ab3b2efb5 OK 2025/04/19 01:58:14 INFO : one: Copied (replaced existing) 2025/04/19 01:58:14 DEBUG : Waiting for deletions to finish 2025/04/19 01:58:15 DEBUG : dst/one: md5 = bbc8e9d01932a688fd2906cea844e599 OK 2025/04/19 01:58:18 DEBUG : CompareDest/one: md5 = ce62addea5f9654dc5f3a74f68117a75 OK 2025/04/19 01:58:18 DEBUG : one: Sizes differ (src 5 vs dst 3) 2025/04/19 01:58:18 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-feyixep3capu/dst': Waiting for checks to finish 2025/04/19 01:58:19 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/04/19 01:58:19 DEBUG : one: Destination found in --compare-dest, skipping 2025/04/19 01:58:19 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-feyixep3capu/dst': Waiting for transfers to finish 2025/04/19 01:58:19 DEBUG : Waiting for deletions to finish 2025/04/19 01:58:19 INFO : There was nothing to transfer 2025/04/19 01:58:20 DEBUG : CompareDest/two: md5 = be1f5ec8d619daf85c7b84c8e217a596 OK 2025/04/19 01:58:21 DEBUG : one: Sizes differ (src 5 vs dst 3) 2025/04/19 01:58:21 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/04/19 01:58:21 DEBUG : one: Destination found in --compare-dest, skipping 2025/04/19 01:58:21 DEBUG : two: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/04/19 01:58:21 DEBUG : two: Destination found in --compare-dest, skipping 2025/04/19 01:58:21 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-feyixep3capu/dst': Waiting for checks to finish 2025/04/19 01:58:21 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-feyixep3capu/dst': Waiting for transfers to finish 2025/04/19 01:58:21 DEBUG : Waiting for deletions to finish 2025/04/19 01:58:21 INFO : There was nothing to transfer 2025/04/19 01:58:22 DEBUG : one: Sizes differ (src 5 vs dst 3) 2025/04/19 01:58:22 DEBUG : two: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/04/19 01:58:22 DEBUG : two: Destination found in --compare-dest, skipping 2025/04/19 01:58:22 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-feyixep3capu/dst': Waiting for checks to finish 2025/04/19 01:58:22 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/04/19 01:58:22 DEBUG : one: Destination found in --compare-dest, skipping 2025/04/19 01:58:22 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-feyixep3capu/dst': Waiting for transfers to finish 2025/04/19 01:58:22 DEBUG : Waiting for deletions to finish 2025/04/19 01:58:22 INFO : There was nothing to transfer sync_test.go:2175: No hash on uploaded file so skipping compare timestamp test 2025/04/19 01:58:23 DEBUG : one: Sizes differ (src 5 vs dst 3) 2025/04/19 01:58:24 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/04/19 01:58:24 DEBUG : one: Destination found in --compare-dest, skipping 2025/04/19 01:58:24 DEBUG : two: Sizes differ (src 5 vs dst 3) 2025/04/19 01:58:24 DEBUG : two: Need to transfer - File not found at Destination 2025/04/19 01:58:24 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-feyixep3capu/dst': Waiting for checks to finish 2025/04/19 01:58:24 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-feyixep3capu/dst': Waiting for transfers to finish 2025/04/19 01:58:25 DEBUG : two: md5 = 41654dd3ca0e75ef5f1f5b0c5b62d896 OK 2025/04/19 01:58:25 INFO : two: Copied (new) 2025/04/19 01:58:25 DEBUG : Waiting for deletions to finish 2025/04/19 01:58:28 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k" 2025/04/19 01:58:28 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" 2025/04/19 01:58:29 DEBUG : gveqi14airsml4bgu7krj116o8: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" 2025/04/19 01:58:29 DEBUG : gveqi14airsml4bgu7krj116o8: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k" --- PASS: TestSyncCompareDest (23.70s) === RUN TestSyncMultipleCompareDest run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-feyixep3capu'", Local "Local file system at /tmp/rclone3509792376", Modify Window "1ms" 2025/04/19 01:58:31 DEBUG : pre-dest1/1: md5 = e16b44416e165e0655529eca2b1c5b02 OK 2025/04/19 01:58:33 DEBUG : pre-dest2/2: md5 = 0a95a8fb4f7ba777569ad74cf372dcba OK 2025/04/19 01:58:34 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-feyixep3capu/dest" 2025/04/19 01:58:34 DEBUG : Creating backend with remote "TestDrive:crypt/iktac5oqe17khgjvgdp5oj3naolfecsltrdlansb2vpgjtapv0j0/rg03c1jvnehrrc617i0lnqjddc" 2025/04/19 01:58:35 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-feyixep3capu/pre-dest1" 2025/04/19 01:58:35 DEBUG : Creating backend with remote "TestDrive:crypt/iktac5oqe17khgjvgdp5oj3naolfecsltrdlansb2vpgjtapv0j0/bbnblvh6k061ssopqrp18kd7gc" 2025/04/19 01:58:36 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-feyixep3capu/pre-dest2" 2025/04/19 01:58:36 DEBUG : Creating backend with remote "TestDrive:crypt/iktac5oqe17khgjvgdp5oj3naolfecsltrdlansb2vpgjtapv0j0/dgicm1h6b5ejvlltm8eeif0bnk" 2025/04/19 01:58:37 DEBUG : 1: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/19 01:58:37 DEBUG : 1: Destination found in --compare-dest, skipping 2025/04/19 01:58:38 DEBUG : 2: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/19 01:58:38 DEBUG : 2: Destination found in --compare-dest, skipping 2025/04/19 01:58:38 DEBUG : 3: Need to transfer - File not found at Destination 2025/04/19 01:58:38 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-feyixep3capu/dest': Waiting for checks to finish 2025/04/19 01:58:38 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-feyixep3capu/dest': Waiting for transfers to finish 2025/04/19 01:58:40 DEBUG : 3: md5 = 1a9c1c6f77c3fa4b11bb12216c84713d OK 2025/04/19 01:58:40 INFO : 3: Copied (new) 2025/04/19 01:58:40 DEBUG : Waiting for deletions to finish 2025/04/19 01:58:43 DEBUG : dgicm1h6b5ejvlltm8eeif0bnk: Rmdir: contains trashed file: "1ghu8geql9vrl726n32nrf65bc" 2025/04/19 01:58:44 DEBUG : bbnblvh6k061ssopqrp18kd7gc: Rmdir: contains trashed file: "skbfko3oil7es0lj68ob574sro" 2025/04/19 01:58:44 DEBUG : rg03c1jvnehrrc617i0lnqjddc: Rmdir: contains trashed file: "g072p7hmjchlnj0gibe64c1epg" --- PASS: TestSyncMultipleCompareDest (15.54s) === RUN TestSyncCopyDest run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-feyixep3capu'", Local "Local file system at /tmp/rclone3509792376", Modify Window "1ms" 2025/04/19 01:58:45 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-feyixep3capu/dst" 2025/04/19 01:58:45 DEBUG : Creating backend with remote "TestDrive:crypt/iktac5oqe17khgjvgdp5oj3naolfecsltrdlansb2vpgjtapv0j0/31u3jie661vd5p8j7rtc3hgbh0" 2025/04/19 01:58:46 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-feyixep3capu/CopyDest" 2025/04/19 01:58:46 DEBUG : Creating backend with remote "TestDrive:crypt/iktac5oqe17khgjvgdp5oj3naolfecsltrdlansb2vpgjtapv0j0/d09o6po3f7bm6ce32vdgs8h9ls" 2025/04/19 01:58:48 DEBUG : one: Need to transfer - File not found at Destination 2025/04/19 01:58:48 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-feyixep3capu/dst': Waiting for checks to finish 2025/04/19 01:58:48 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-feyixep3capu/dst': Waiting for transfers to finish 2025/04/19 01:58:50 DEBUG : one: md5 = 4434c5936007981f6d96653776aa6051 OK 2025/04/19 01:58:50 INFO : one: Copied (new) 2025/04/19 01:58:50 DEBUG : Waiting for deletions to finish 2025/04/19 01:58:51 DEBUG : one: Sizes differ (src 5 vs dst 3) 2025/04/19 01:58:51 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-feyixep3capu/dst': Waiting for checks to finish 2025/04/19 01:58:52 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-feyixep3capu/dst': Waiting for transfers to finish 2025/04/19 01:58:53 DEBUG : one: md5 = 9157e79459cdf822c6c402ace4fc8149 OK 2025/04/19 01:58:53 INFO : one: Copied (replaced existing) 2025/04/19 01:58:53 DEBUG : Waiting for deletions to finish 2025/04/19 01:58:55 DEBUG : dst/one: md5 = ac2be7ac70cbedd6bb5be07412b6a367 OK 2025/04/19 01:58:57 DEBUG : CopyDest/one: md5 = 0f4177793100b78dde93f7d5817a2613 OK 2025/04/19 01:58:57 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-feyixep3capu/BackupDir" 2025/04/19 01:58:57 DEBUG : Creating backend with remote "TestDrive:crypt/iktac5oqe17khgjvgdp5oj3naolfecsltrdlansb2vpgjtapv0j0/s6dbk3lfi7c9kfvo6j7bla9m0g" 2025/04/19 01:58:59 DEBUG : one: Sizes differ (src 5 vs dst 3) 2025/04/19 01:58:59 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-feyixep3capu/dst': Waiting for checks to finish 2025/04/19 01:58:59 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/04/19 01:58:59 DEBUG : one: Sizes differ (src 5 vs dst 3) 2025/04/19 01:59:01 INFO : one: Moved (server-side) 2025/04/19 01:59:02 INFO : one: Copied (server-side copy) 2025/04/19 01:59:02 DEBUG : one: Destination found in --copy-dest, using server-side copy 2025/04/19 01:59:02 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-feyixep3capu/dst': Waiting for transfers to finish 2025/04/19 01:59:02 DEBUG : Waiting for deletions to finish 2025/04/19 01:59:04 DEBUG : CopyDest/two: md5 = 3f7a7d4c43802e2335216af7c8941c0e OK 2025/04/19 01:59:04 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/04/19 01:59:04 DEBUG : one: Unchanged skipping 2025/04/19 01:59:05 DEBUG : two: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/04/19 01:59:05 INFO : two: Copied (server-side copy) 2025/04/19 01:59:05 DEBUG : two: Destination found in --copy-dest, using server-side copy 2025/04/19 01:59:05 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-feyixep3capu/dst': Waiting for checks to finish 2025/04/19 01:59:05 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-feyixep3capu/dst': Waiting for transfers to finish 2025/04/19 01:59:05 DEBUG : Waiting for deletions to finish 2025/04/19 01:59:06 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/04/19 01:59:06 DEBUG : one: Unchanged skipping 2025/04/19 01:59:06 DEBUG : two: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/04/19 01:59:06 DEBUG : two: Unchanged skipping 2025/04/19 01:59:06 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-feyixep3capu/dst': Waiting for checks to finish 2025/04/19 01:59:06 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-feyixep3capu/dst': Waiting for transfers to finish 2025/04/19 01:59:06 DEBUG : Waiting for deletions to finish 2025/04/19 01:59:06 INFO : There was nothing to transfer 2025/04/19 01:59:08 DEBUG : CopyDest/three: md5 = 8eb630fe36d36e90d8906c0741a1366e OK 2025/04/19 01:59:09 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/04/19 01:59:09 DEBUG : one: Unchanged skipping 2025/04/19 01:59:09 DEBUG : three: Sizes differ (src 7 vs dst 5) 2025/04/19 01:59:09 DEBUG : three: Destination not found in --copy-dest 2025/04/19 01:59:09 DEBUG : three: Need to transfer - File not found at Destination 2025/04/19 01:59:09 DEBUG : two: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/04/19 01:59:09 DEBUG : two: Unchanged skipping 2025/04/19 01:59:09 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-feyixep3capu/dst': Waiting for checks to finish 2025/04/19 01:59:09 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-feyixep3capu/dst': Waiting for transfers to finish 2025/04/19 01:59:10 DEBUG : three: md5 = e63fb73866ff54a326184e45f86416e7 OK 2025/04/19 01:59:10 INFO : three: Copied (new) 2025/04/19 01:59:10 DEBUG : Waiting for deletions to finish 2025/04/19 01:59:15 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "b6jdmn2b1adrhc8vikh7edr9os" 2025/04/19 01:59:15 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k" 2025/04/19 01:59:15 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" 2025/04/19 01:59:15 DEBUG : d09o6po3f7bm6ce32vdgs8h9ls: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" 2025/04/19 01:59:15 DEBUG : d09o6po3f7bm6ce32vdgs8h9ls: Rmdir: contains trashed file: "b6jdmn2b1adrhc8vikh7edr9os" 2025/04/19 01:59:15 DEBUG : d09o6po3f7bm6ce32vdgs8h9ls: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k" 2025/04/19 01:59:16 DEBUG : s6dbk3lfi7c9kfvo6j7bla9m0g: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" --- PASS: TestSyncCopyDest (31.75s) === RUN TestSyncBackupDir run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-feyixep3capu'", Local "Local file system at /tmp/rclone3509792376", Modify Window "1ms" 2025/04/19 01:59:19 DEBUG : dst/one: md5 = d681d4522083c7a6fde264f647b46a79 OK 2025/04/19 01:59:20 DEBUG : dst/two: md5 = 37d2f52dee3e5e762e8527f378608418 OK 2025/04/19 01:59:21 DEBUG : dst/three.txt: md5 = 960b7db9daed4b07b6d708b203e31b82 OK 2025/04/19 01:59:22 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-feyixep3capu/dst" 2025/04/19 01:59:22 DEBUG : Creating backend with remote "TestDrive:crypt/iktac5oqe17khgjvgdp5oj3naolfecsltrdlansb2vpgjtapv0j0/31u3jie661vd5p8j7rtc3hgbh0" 2025/04/19 01:59:22 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-feyixep3capu/backup" 2025/04/19 01:59:23 DEBUG : Creating backend with remote "TestDrive:crypt/iktac5oqe17khgjvgdp5oj3naolfecsltrdlansb2vpgjtapv0j0/1nrff024r7pq65ecp72fc28jb0" 2025/04/19 01:59:24 DEBUG : one: Sizes differ (src 4 vs dst 3) 2025/04/19 01:59:24 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/19 01:59:24 DEBUG : two: Unchanged skipping 2025/04/19 01:59:24 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-feyixep3capu/dst': Waiting for checks to finish 2025/04/19 01:59:26 INFO : one: Moved (server-side) 2025/04/19 01:59:26 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-feyixep3capu/dst': Waiting for transfers to finish 2025/04/19 01:59:27 DEBUG : one: md5 = 6cd17e67ffa15bc4b8a0d48e49a4bb47 OK 2025/04/19 01:59:27 INFO : one: Copied (new) 2025/04/19 01:59:27 DEBUG : Waiting for deletions to finish 2025/04/19 01:59:28 INFO : three.txt: Moved (server-side) 2025/04/19 01:59:28 INFO : three.txt: Moved into backup dir 2025/04/19 01:59:29 DEBUG : dst/three.txt: md5 = 90edca21e037a150e77785270f884483 OK 2025/04/19 01:59:30 DEBUG : one: Sizes differ (src 5 vs dst 4) 2025/04/19 01:59:30 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/19 01:59:30 DEBUG : two: Unchanged skipping 2025/04/19 01:59:30 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-feyixep3capu/dst': Waiting for checks to finish 2025/04/19 01:59:31 INFO : one: Deleted 2025/04/19 01:59:31 INFO : one: Moved (server-side) 2025/04/19 01:59:31 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-feyixep3capu/dst': Waiting for transfers to finish 2025/04/19 01:59:33 DEBUG : one: md5 = a5782b200f93f1f8b90934b73af5fc42 OK 2025/04/19 01:59:33 INFO : one: Copied (new) 2025/04/19 01:59:33 DEBUG : Waiting for deletions to finish 2025/04/19 01:59:33 INFO : three.txt: Deleted 2025/04/19 01:59:34 INFO : three.txt: Moved (server-side) 2025/04/19 01:59:34 INFO : three.txt: Moved into backup dir 2025/04/19 01:59:37 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" 2025/04/19 01:59:37 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k" 2025/04/19 01:59:37 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "tr2hj63d80ftlmvm6a952snjcc" 2025/04/19 01:59:37 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" 2025/04/19 01:59:37 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" 2025/04/19 01:59:37 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "tr2hj63d80ftlmvm6a952snjcc" --- PASS: TestSyncBackupDir (21.42s) === RUN TestSyncBackupDirWithSuffix run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-feyixep3capu'", Local "Local file system at /tmp/rclone3509792376", Modify Window "1ms" 2025/04/19 01:59:40 DEBUG : dst/one: md5 = cdfe209e2dc961f70c1c74a4de6cfbd4 OK 2025/04/19 01:59:41 DEBUG : dst/two: md5 = 169cb2f5c35505a223035b57c40c3a06 OK 2025/04/19 01:59:43 DEBUG : dst/three.txt: md5 = 60702363d53849e3c3326c0dbd332228 OK 2025/04/19 01:59:43 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-feyixep3capu/dst" 2025/04/19 01:59:43 DEBUG : Creating backend with remote "TestDrive:crypt/iktac5oqe17khgjvgdp5oj3naolfecsltrdlansb2vpgjtapv0j0/31u3jie661vd5p8j7rtc3hgbh0" 2025/04/19 01:59:44 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-feyixep3capu/backup" 2025/04/19 01:59:44 DEBUG : Creating backend with remote "TestDrive:crypt/iktac5oqe17khgjvgdp5oj3naolfecsltrdlansb2vpgjtapv0j0/1nrff024r7pq65ecp72fc28jb0" 2025/04/19 01:59:46 DEBUG : one: Sizes differ (src 4 vs dst 3) 2025/04/19 01:59:46 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/19 01:59:46 DEBUG : two: Unchanged skipping 2025/04/19 01:59:46 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-feyixep3capu/dst': Waiting for checks to finish 2025/04/19 01:59:47 INFO : one: Moved (server-side) to: one.bak 2025/04/19 01:59:47 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-feyixep3capu/dst': Waiting for transfers to finish 2025/04/19 01:59:49 DEBUG : one: md5 = 47442784ef2900486bf35ff78815dea5 OK 2025/04/19 01:59:49 INFO : one: Copied (new) 2025/04/19 01:59:49 DEBUG : Waiting for deletions to finish 2025/04/19 01:59:49 INFO : three.txt: Moved (server-side) to: three.txt.bak 2025/04/19 01:59:49 INFO : three.txt: Moved into backup dir 2025/04/19 01:59:51 DEBUG : dst/three.txt: md5 = e144e4748dca56a46236aff56bfdeefe OK 2025/04/19 01:59:52 DEBUG : one: Sizes differ (src 5 vs dst 4) 2025/04/19 01:59:52 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/19 01:59:52 DEBUG : two: Unchanged skipping 2025/04/19 01:59:52 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-feyixep3capu/dst': Waiting for checks to finish 2025/04/19 01:59:52 INFO : one.bak: Deleted 2025/04/19 01:59:53 INFO : one: Moved (server-side) to: one.bak 2025/04/19 01:59:53 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-feyixep3capu/dst': Waiting for transfers to finish 2025/04/19 01:59:54 DEBUG : one: md5 = d8e89e255117be8ad920a96383af7bca OK 2025/04/19 01:59:54 INFO : one: Copied (new) 2025/04/19 01:59:54 DEBUG : Waiting for deletions to finish 2025/04/19 01:59:55 INFO : three.txt.bak: Deleted 2025/04/19 01:59:55 INFO : three.txt: Moved (server-side) to: three.txt.bak 2025/04/19 01:59:55 INFO : three.txt: Moved into backup dir 2025/04/19 01:59:58 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" 2025/04/19 01:59:58 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k" 2025/04/19 01:59:59 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "qltcak2uaegtmcoa8vijdppbp8" 2025/04/19 01:59:59 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "sk91qgsqfn0r271r2ehsaoc20c" 2025/04/19 01:59:59 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "sk91qgsqfn0r271r2ehsaoc20c" 2025/04/19 01:59:59 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "qltcak2uaegtmcoa8vijdppbp8" --- PASS: TestSyncBackupDirWithSuffix (21.75s) === RUN TestSyncBackupDirWithSuffixKeepExtension run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-feyixep3capu'", Local "Local file system at /tmp/rclone3509792376", Modify Window "1ms" 2025/04/19 02:00:02 DEBUG : dst/one: md5 = 30fdeeb061b159cc27ea6a890801c67b OK 2025/04/19 02:00:03 DEBUG : dst/two: md5 = dda9ece1fb30b73ae3622d21cb4352b7 OK 2025/04/19 02:00:05 DEBUG : dst/three.txt: md5 = 7b16bd3e749de83625b69532ddd6d775 OK 2025/04/19 02:00:05 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-feyixep3capu/dst" 2025/04/19 02:00:05 DEBUG : Creating backend with remote "TestDrive:crypt/iktac5oqe17khgjvgdp5oj3naolfecsltrdlansb2vpgjtapv0j0/31u3jie661vd5p8j7rtc3hgbh0" 2025/04/19 02:00:06 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-feyixep3capu/backup" 2025/04/19 02:00:06 DEBUG : Creating backend with remote "TestDrive:crypt/iktac5oqe17khgjvgdp5oj3naolfecsltrdlansb2vpgjtapv0j0/1nrff024r7pq65ecp72fc28jb0" 2025/04/19 02:00:08 DEBUG : one: Sizes differ (src 4 vs dst 3) 2025/04/19 02:00:08 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/19 02:00:08 DEBUG : two: Unchanged skipping 2025/04/19 02:00:08 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-feyixep3capu/dst': Waiting for checks to finish 2025/04/19 02:00:09 INFO : one: Moved (server-side) to: one-2019-01-01 2025/04/19 02:00:09 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-feyixep3capu/dst': Waiting for transfers to finish 2025/04/19 02:00:11 DEBUG : one: md5 = 9bd7fb4222d3bd0ca62807a0c401fd5a OK 2025/04/19 02:00:11 INFO : one: Copied (new) 2025/04/19 02:00:11 DEBUG : Waiting for deletions to finish 2025/04/19 02:00:11 INFO : three.txt: Moved (server-side) to: three-2019-01-01.txt 2025/04/19 02:00:11 INFO : three.txt: Moved into backup dir 2025/04/19 02:00:13 DEBUG : dst/three.txt: md5 = e87e9fa992c2ed823bdb3d7485a710a3 OK 2025/04/19 02:00:14 DEBUG : one: Sizes differ (src 5 vs dst 4) 2025/04/19 02:00:14 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/19 02:00:14 DEBUG : two: Unchanged skipping 2025/04/19 02:00:14 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-feyixep3capu/dst': Waiting for checks to finish 2025/04/19 02:00:15 INFO : one-2019-01-01: Deleted 2025/04/19 02:00:15 INFO : one: Moved (server-side) to: one-2019-01-01 2025/04/19 02:00:15 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-feyixep3capu/dst': Waiting for transfers to finish 2025/04/19 02:00:16 DEBUG : one: md5 = a582d337beff351fabcded697aabb53a OK 2025/04/19 02:00:16 INFO : one: Copied (new) 2025/04/19 02:00:16 DEBUG : Waiting for deletions to finish 2025/04/19 02:00:17 INFO : three-2019-01-01.txt: Deleted 2025/04/19 02:00:18 INFO : three.txt: Moved (server-side) to: three-2019-01-01.txt 2025/04/19 02:00:18 INFO : three.txt: Moved into backup dir 2025/04/19 02:00:21 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" 2025/04/19 02:00:21 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k" 2025/04/19 02:00:21 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "qtq2f6qq4lgpsmj88vb7147qje3prudmtfdtr2342fth58vo9a50" 2025/04/19 02:00:21 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "jcjl1bv3ep0v8kt35lqql1co90" 2025/04/19 02:00:21 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "qtq2f6qq4lgpsmj88vb7147qje3prudmtfdtr2342fth58vo9a50" 2025/04/19 02:00:21 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "jcjl1bv3ep0v8kt35lqql1co90" --- PASS: TestSyncBackupDirWithSuffixKeepExtension (22.07s) === RUN TestSyncBackupDirSuffixOnly run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-feyixep3capu'", Local "Local file system at /tmp/rclone3509792376", Modify Window "1ms" 2025/04/19 02:00:24 DEBUG : dst/one: md5 = 2ebed8b1c69545340588a68b5fc99ad5 OK 2025/04/19 02:00:25 DEBUG : dst/two: md5 = e4137a7c6c9e1bd648f1f5da27e59d71 OK 2025/04/19 02:00:26 DEBUG : dst/three.txt: md5 = 13e8a6655b3a09acc0d323e7f05d1ab0 OK 2025/04/19 02:00:27 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-feyixep3capu/dst" 2025/04/19 02:00:27 DEBUG : Config file has changed externally - reloading 2025/04/19 02:00:27 DEBUG : Creating backend with remote "TestDrive:crypt/iktac5oqe17khgjvgdp5oj3naolfecsltrdlansb2vpgjtapv0j0/31u3jie661vd5p8j7rtc3hgbh0" 2025/04/19 02:00:28 DEBUG : one: Sizes differ (src 4 vs dst 3) 2025/04/19 02:00:28 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/19 02:00:28 DEBUG : two: Unchanged skipping 2025/04/19 02:00:28 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-feyixep3capu/dst': Waiting for checks to finish 2025/04/19 02:00:28 INFO : one: Moved (server-side) to: one.bak 2025/04/19 02:00:28 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-feyixep3capu/dst': Waiting for transfers to finish 2025/04/19 02:00:30 DEBUG : one: md5 = 9a2c93dced94abfb50f7146952083e19 OK 2025/04/19 02:00:30 INFO : one: Copied (new) 2025/04/19 02:00:30 DEBUG : Waiting for deletions to finish 2025/04/19 02:00:30 INFO : three.txt: Moved (server-side) to: three.txt.bak 2025/04/19 02:00:30 INFO : three.txt: Moved into backup dir 2025/04/19 02:00:32 DEBUG : dst/three.txt: md5 = e1f3152ba91870247513d54ee50f2054 OK 2025/04/19 02:00:33 DEBUG : one.bak: Excluded (Path Filter) 2025/04/19 02:00:33 DEBUG : three.txt.bak: Excluded (Path Filter) 2025/04/19 02:00:33 DEBUG : one: Sizes differ (src 5 vs dst 4) 2025/04/19 02:00:33 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/19 02:00:33 DEBUG : two: Unchanged skipping 2025/04/19 02:00:33 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-feyixep3capu/dst': Waiting for checks to finish 2025/04/19 02:00:34 INFO : one.bak: Deleted 2025/04/19 02:00:34 INFO : one: Moved (server-side) to: one.bak 2025/04/19 02:00:34 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-feyixep3capu/dst': Waiting for transfers to finish 2025/04/19 02:00:35 DEBUG : one: md5 = 17840a04db62b262cb36861aa947be13 OK 2025/04/19 02:00:35 INFO : one: Copied (new) 2025/04/19 02:00:35 DEBUG : Waiting for deletions to finish 2025/04/19 02:00:36 INFO : three.txt.bak: Deleted 2025/04/19 02:00:37 INFO : three.txt: Moved (server-side) to: three.txt.bak 2025/04/19 02:00:37 INFO : three.txt: Moved into backup dir 2025/04/19 02:00:40 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" 2025/04/19 02:00:40 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "sk91qgsqfn0r271r2ehsaoc20c" 2025/04/19 02:00:40 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "qltcak2uaegtmcoa8vijdppbp8" 2025/04/19 02:00:40 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "qltcak2uaegtmcoa8vijdppbp8" 2025/04/19 02:00:40 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "sk91qgsqfn0r271r2ehsaoc20c" 2025/04/19 02:00:40 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k" --- PASS: TestSyncBackupDirSuffixOnly (18.29s) === RUN TestSyncSuffix run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-feyixep3capu'", Local "Local file system at /tmp/rclone3509792376", Modify Window "1ms" 2025/04/19 02:00:42 DEBUG : dst/one: md5 = ff45123afe50bbdecdc459b3e284810b OK 2025/04/19 02:00:44 DEBUG : dst/two: md5 = d0e734d6b60b785787bd30d32b46c3b4 OK 2025/04/19 02:00:45 DEBUG : dst/three.txt: md5 = f068a53dbc3d9d5de0f16aeb1e07aa57 OK 2025/04/19 02:00:45 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-feyixep3capu/dst" 2025/04/19 02:00:46 DEBUG : Creating backend with remote "TestDrive:crypt/iktac5oqe17khgjvgdp5oj3naolfecsltrdlansb2vpgjtapv0j0/31u3jie661vd5p8j7rtc3hgbh0" 2025/04/19 02:00:47 DEBUG : one: Sizes differ (src 4 vs dst 3) 2025/04/19 02:00:47 INFO : one: Moved (server-side) to: one.bak 2025/04/19 02:00:49 DEBUG : one: md5 = 990388ae35a0e2101b3df93a38d7ccc7 OK 2025/04/19 02:00:49 INFO : one: Copied (new) 2025/04/19 02:00:49 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/19 02:00:49 DEBUG : two: Unchanged skipping 2025/04/19 02:00:49 DEBUG : three.txt: Sizes differ (src 6 vs dst 5) 2025/04/19 02:00:50 INFO : three.txt: Moved (server-side) to: three.txt.bak 2025/04/19 02:00:51 DEBUG : three.txt: md5 = 63c2bbf1bae6cdac8cb586db10debc44 OK 2025/04/19 02:00:51 INFO : three.txt: Copied (new) 2025/04/19 02:00:52 DEBUG : one: Sizes differ (src 5 vs dst 4) 2025/04/19 02:00:53 INFO : one.bak: Deleted 2025/04/19 02:00:53 INFO : one: Moved (server-side) to: one.bak 2025/04/19 02:00:55 DEBUG : one: md5 = e8997b3a745335670cb0eb5cbea4d8c1 OK 2025/04/19 02:00:55 INFO : one: Copied (new) 2025/04/19 02:00:55 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/19 02:00:55 DEBUG : two: Unchanged skipping 2025/04/19 02:00:55 DEBUG : three.txt: Sizes differ (src 19 vs dst 6) 2025/04/19 02:00:56 INFO : three.txt.bak: Deleted 2025/04/19 02:00:56 INFO : three.txt: Moved (server-side) to: three.txt.bak 2025/04/19 02:00:58 DEBUG : three.txt: md5 = fad22e3e3e86a7c9961e43acc74f670e OK 2025/04/19 02:00:58 INFO : three.txt: Copied (new) 2025/04/19 02:01:01 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" 2025/04/19 02:01:01 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "tr2hj63d80ftlmvm6a952snjcc" 2025/04/19 02:01:01 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "qltcak2uaegtmcoa8vijdppbp8" 2025/04/19 02:01:01 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "qltcak2uaegtmcoa8vijdppbp8" 2025/04/19 02:01:01 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "sk91qgsqfn0r271r2ehsaoc20c" 2025/04/19 02:01:01 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "sk91qgsqfn0r271r2ehsaoc20c" 2025/04/19 02:01:01 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k" --- PASS: TestSyncSuffix (21.57s) === RUN TestSyncSuffixKeepExtension run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-feyixep3capu'", Local "Local file system at /tmp/rclone3509792376", Modify Window "1ms" 2025/04/19 02:01:04 DEBUG : dst/one: md5 = 25a4f7699d5a24b721049af44c02b627 OK 2025/04/19 02:01:05 DEBUG : dst/two: md5 = 9ef68260b8f3e43b6c0161e53c737bc7 OK 2025/04/19 02:01:06 DEBUG : dst/three.txt: md5 = 4959e9245b4de89e4fa22a1f2ae4988c OK 2025/04/19 02:01:07 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-feyixep3capu/dst" 2025/04/19 02:01:07 DEBUG : Creating backend with remote "TestDrive:crypt/iktac5oqe17khgjvgdp5oj3naolfecsltrdlansb2vpgjtapv0j0/31u3jie661vd5p8j7rtc3hgbh0" 2025/04/19 02:01:08 DEBUG : one: Sizes differ (src 4 vs dst 3) 2025/04/19 02:01:08 INFO : one: Moved (server-side) to: one-2019-01-01 2025/04/19 02:01:10 DEBUG : one: md5 = 238ef884014161041406049529b213c1 OK 2025/04/19 02:01:10 INFO : one: Copied (new) 2025/04/19 02:01:10 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/19 02:01:10 DEBUG : two: Unchanged skipping 2025/04/19 02:01:10 DEBUG : three.txt: Sizes differ (src 6 vs dst 5) 2025/04/19 02:01:11 INFO : three.txt: Moved (server-side) to: three-2019-01-01.txt 2025/04/19 02:01:12 DEBUG : three.txt: md5 = 34b0fc3c10e201cc71916eb9849e7d2c OK 2025/04/19 02:01:12 INFO : three.txt: Copied (new) 2025/04/19 02:01:13 DEBUG : one: Sizes differ (src 5 vs dst 4) 2025/04/19 02:01:14 INFO : one-2019-01-01: Deleted 2025/04/19 02:01:15 INFO : one: Moved (server-side) to: one-2019-01-01 2025/04/19 02:01:16 DEBUG : one: md5 = 065d8e71bbc2b1a0866c90b17207d854 OK 2025/04/19 02:01:16 INFO : one: Copied (new) 2025/04/19 02:01:16 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/19 02:01:16 DEBUG : two: Unchanged skipping 2025/04/19 02:01:16 DEBUG : three.txt: Sizes differ (src 19 vs dst 6) 2025/04/19 02:01:17 INFO : three-2019-01-01.txt: Deleted 2025/04/19 02:01:18 INFO : three.txt: Moved (server-side) to: three-2019-01-01.txt 2025/04/19 02:01:19 DEBUG : three.txt: md5 = ea739348a751999d2a930f4c11f016a8 OK 2025/04/19 02:01:19 INFO : three.txt: Copied (new) 2025/04/19 02:01:22 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "tr2hj63d80ftlmvm6a952snjcc" 2025/04/19 02:01:22 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" 2025/04/19 02:01:22 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "jcjl1bv3ep0v8kt35lqql1co90" 2025/04/19 02:01:22 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "jcjl1bv3ep0v8kt35lqql1co90" 2025/04/19 02:01:22 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "qtq2f6qq4lgpsmj88vb7147qje3prudmtfdtr2342fth58vo9a50" 2025/04/19 02:01:22 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k" 2025/04/19 02:01:22 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "qtq2f6qq4lgpsmj88vb7147qje3prudmtfdtr2342fth58vo9a50" --- PASS: TestSyncSuffixKeepExtension (21.22s) === RUN TestSyncUTFNorm run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-feyixep3capu'", Local "Local file system at /tmp/rclone3509792376", Modify Window "1ms" 2025/04/19 02:01:24 DEBUG : Testêé: md5 = 8ba9fda9021094b27cf5e9b28076bb9e OK 2025/04/19 02:01:25 DEBUG : Testêé: Sizes differ (src 14 vs dst 18) 2025/04/19 02:01:25 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-feyixep3capu': Waiting for checks to finish 2025/04/19 02:01:25 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-feyixep3capu': Waiting for transfers to finish 2025/04/19 02:01:26 DEBUG : Testêé: md5 = a64d3324b06ce9a4e14d7f1f006b36a0 OK 2025/04/19 02:01:26 INFO : Testêé: Copied (replaced existing) to: Testêé 2025/04/19 02:01:26 DEBUG : Waiting for deletions to finish --- PASS: TestSyncUTFNorm (3.99s) === RUN TestSyncImmutable run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-feyixep3capu'", Local "Local file system at /tmp/rclone3509792376", Modify Window "1ms" 2025/04/19 02:01:27 DEBUG : existing: Need to transfer - File not found at Destination 2025/04/19 02:01:27 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-feyixep3capu': Waiting for checks to finish 2025/04/19 02:01:27 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-feyixep3capu': Waiting for transfers to finish 2025/04/19 02:01:29 DEBUG : existing: md5 = 180324174b223ed7e0daf9788148ece9 OK 2025/04/19 02:01:29 INFO : existing: Copied (new) 2025/04/19 02:01:29 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-feyixep3capu'", Local "Local file system at /tmp/rclone3509792376", Modify Window "1ms" 2025/04/19 02:01:29 DEBUG : existing: Sizes differ (src 8 vs dst 6) 2025/04/19 02:01:29 ERROR : existing: Source and destination exist but do not match: immutable file modified 2025/04/19 02:01:29 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-feyixep3capu': Waiting for checks to finish 2025/04/19 02:01:29 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-feyixep3capu': Waiting for transfers to finish 2025/04/19 02:01:29 ERROR : Encrypted drive 'TestCryptDrive:rclone-test-feyixep3capu': not deleting files as there were IO errors 2025/04/19 02:01:29 ERROR : Encrypted drive 'TestCryptDrive:rclone-test-feyixep3capu': not deleting directories as there were IO errors run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-feyixep3capu'", Local "Local file system at /tmp/rclone3509792376", Modify Window "1ms" --- PASS: TestSyncImmutable (4.19s) === RUN TestSyncIgnoreCase run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-feyixep3capu'", Local "Local file system at /tmp/rclone3509792376", Modify Window "1ms" 2025/04/19 02:01:32 DEBUG : EXISTING: md5 = 148811dffbde21fa9bf4fc23b072b685 OK 2025/04/19 02:01:33 DEBUG : existing: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/19 02:01:33 DEBUG : existing: Unchanged skipping 2025/04/19 02:01:33 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-feyixep3capu': Waiting for checks to finish 2025/04/19 02:01:33 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-feyixep3capu': Waiting for transfers to finish 2025/04/19 02:01:33 DEBUG : Waiting for deletions to finish 2025/04/19 02:01:33 INFO : There was nothing to transfer --- PASS: TestSyncIgnoreCase (2.75s) === RUN TestFixCase run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-feyixep3capu'", Local "Local file system at /tmp/rclone3509792376", Modify Window "1ms" sync_test.go:2635: Skipping test as local or remote are case-sensitive --- SKIP: TestFixCase (0.42s) === RUN TestMaxTransfer === RUN TestMaxTransfer/Hard run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-feyixep3capu'", Local "Local file system at /tmp/rclone3509792376", 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-feyixep3capu'", Local "Local file system at /tmp/rclone3509792376", 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-feyixep3capu'", Local "Local file system at /tmp/rclone3509792376", Modify Window "1ms" sync_test.go:2674: This test only runs on local --- PASS: TestMaxTransfer (1.21s) --- SKIP: TestMaxTransfer/Hard (0.40s) --- SKIP: TestMaxTransfer/Soft (0.41s) --- SKIP: TestMaxTransfer/Cautious (0.40s) === RUN TestSyncConcurrentDelete run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-feyixep3capu'", Local "Local file system at /tmp/rclone3509792376", Modify Window "1ms" 2025/04/19 02:01:37 DEBUG : both0: md5 = e5d6379bb56acd768912c2376a631580 OK 2025/04/19 02:01:38 DEBUG : only0: md5 = 5ed25bf2392f4c0cbee2321f1f5d43b8 OK 2025/04/19 02:01:39 DEBUG : both1: md5 = 87f9ecac51b949c818e5579f7db2476f OK 2025/04/19 02:01:41 DEBUG : only1: md5 = 48273bcd397223278fdc3667a28ce559 OK 2025/04/19 02:01:42 DEBUG : both2: md5 = d5e2dbcda29f8b88f8bf823c10e9da25 OK 2025/04/19 02:01:44 DEBUG : only2: md5 = 95027bc775ec1ad057833cafe91948bf OK 2025/04/19 02:01:45 DEBUG : both3: md5 = 21c6d351c80d9997f0dd197440502d13 OK 2025/04/19 02:01:46 DEBUG : only3: md5 = aa7c0c7d78081ddd53e7039ed20ea8ef OK 2025/04/19 02:01:48 DEBUG : both4: md5 = 92017358fd2aa36664ef5eb873316bed OK 2025/04/19 02:01:49 DEBUG : only4: md5 = c0b70df344d282ca40efe43852628946 OK 2025/04/19 02:01:51 DEBUG : both5: md5 = 45a139cd2a1edd892afda7c4164332d5 OK 2025/04/19 02:01:52 DEBUG : only5: md5 = 6d9120a2d6be59c8898992994eceb3a7 OK 2025/04/19 02:01:53 DEBUG : both6: md5 = 3903ebb901cc11412c31f914351cb1fc OK 2025/04/19 02:01:54 DEBUG : only6: md5 = 92ddcb9e6ccc3e59a638f67c700afc19 OK 2025/04/19 02:01:56 DEBUG : both7: md5 = 7fd18e38241985b5b0c211ea2d07f71b OK 2025/04/19 02:01:57 DEBUG : only7: md5 = 37185b92bf9e4956e4c7804f3e8725a1 OK 2025/04/19 02:01:58 DEBUG : both8: md5 = 6a88fd52a3c2c6c23784e420b259acd7 OK 2025/04/19 02:02:00 DEBUG : only8: md5 = 95639f520b1ab547ef97f8da36fb17ea OK 2025/04/19 02:02:01 DEBUG : both9: md5 = f428bf9b41e4251d6962265f6fe18f09 OK 2025/04/19 02:02:02 DEBUG : only9: md5 = b9e67dd251bcc79d113b0de0e0cbbffd OK 2025/04/19 02:02:03 DEBUG : both10: md5 = 0811b8b56497c4c129ebb4a3d33c7d01 OK 2025/04/19 02:02:05 DEBUG : only10: md5 = 50549ff678974f6a2cc42ef5a5e9f225 OK 2025/04/19 02:02:06 DEBUG : both11: md5 = fde5cb67c8335290f4fa52de60869247 OK 2025/04/19 02:02:08 DEBUG : only11: md5 = 14ade648e3895b39b188e79ce72b27d6 OK 2025/04/19 02:02:09 DEBUG : both12: md5 = d2efd8ad91b946b510ea9d2f22292961 OK 2025/04/19 02:02:10 DEBUG : only12: md5 = 8497fe3fc540f0b690e229758c1e16e2 OK 2025/04/19 02:02:12 DEBUG : both13: md5 = 92a79938e4ec84703b96a2e722d462ce OK 2025/04/19 02:02:13 DEBUG : only13: md5 = 32aebd739f7f7a4637c524bc81011826 OK 2025/04/19 02:02:14 DEBUG : both14: md5 = aeded53d316fc6c1bc228060838056a9 OK 2025/04/19 02:02:16 DEBUG : only14: md5 = 21b3eb39b3e9f4649581f4e73509a4ed OK 2025/04/19 02:02:17 DEBUG : both15: md5 = f38bf644bade668eeeb9080e6dd2bc05 OK 2025/04/19 02:02:18 DEBUG : only15: md5 = a3d318a1bbba0b32936c37476e171340 OK 2025/04/19 02:02:19 DEBUG : both16: md5 = 6e60155a7c656b4191cc264f47c98932 OK 2025/04/19 02:02:21 DEBUG : only16: md5 = dbca92d4fef04f309ab8fcfd637ac02a OK 2025/04/19 02:02:22 DEBUG : both17: md5 = 9eb5760d0c710bff7f2a7d9a70d66b8c OK 2025/04/19 02:02:23 DEBUG : only17: md5 = 3f904fd487e81d10d75fecef05ee6cf3 OK 2025/04/19 02:02:25 DEBUG : both18: md5 = ca7650ec25a4a2a940858a3ee22d0235 OK 2025/04/19 02:02:26 DEBUG : only18: md5 = 0b606638d38a6acfb8c4a3bb98b2bea6 OK 2025/04/19 02:02:27 DEBUG : both19: md5 = a58c697f878b826a2c2f9a40f20597bb OK 2025/04/19 02:02:29 DEBUG : only19: md5 = ecf3c547952692376507d13ee2138c5b OK 2025/04/19 02:02:29 DEBUG : both0: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/19 02:02:29 DEBUG : both10: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/19 02:02:29 DEBUG : both11: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/19 02:02:29 DEBUG : both1: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/19 02:02:29 DEBUG : both10: Unchanged skipping 2025/04/19 02:02:29 DEBUG : both12: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/19 02:02:29 DEBUG : both12: Unchanged skipping 2025/04/19 02:02:29 DEBUG : both13: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/19 02:02:29 DEBUG : both13: Unchanged skipping 2025/04/19 02:02:29 DEBUG : both14: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/19 02:02:29 DEBUG : both14: Unchanged skipping 2025/04/19 02:02:29 DEBUG : both15: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/19 02:02:29 DEBUG : both15: Unchanged skipping 2025/04/19 02:02:29 DEBUG : both16: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/19 02:02:29 DEBUG : both16: Unchanged skipping 2025/04/19 02:02:29 DEBUG : both17: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/19 02:02:29 DEBUG : both17: Unchanged skipping 2025/04/19 02:02:29 DEBUG : both18: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/19 02:02:29 DEBUG : both18: Unchanged skipping 2025/04/19 02:02:29 DEBUG : both19: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/19 02:02:29 DEBUG : both19: Unchanged skipping 2025/04/19 02:02:29 DEBUG : both2: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/19 02:02:29 DEBUG : both2: Unchanged skipping 2025/04/19 02:02:29 DEBUG : both3: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/19 02:02:29 DEBUG : both3: Unchanged skipping 2025/04/19 02:02:29 DEBUG : both4: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/19 02:02:29 DEBUG : both4: Unchanged skipping 2025/04/19 02:02:29 DEBUG : both5: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/19 02:02:29 DEBUG : both5: Unchanged skipping 2025/04/19 02:02:29 DEBUG : both6: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/19 02:02:29 DEBUG : both6: Unchanged skipping 2025/04/19 02:02:29 DEBUG : both7: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/19 02:02:29 DEBUG : both7: Unchanged skipping 2025/04/19 02:02:29 DEBUG : both8: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/19 02:02:29 DEBUG : both8: Unchanged skipping 2025/04/19 02:02:29 DEBUG : both9: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/19 02:02:29 DEBUG : both9: Unchanged skipping 2025/04/19 02:02:29 DEBUG : both0: Unchanged skipping 2025/04/19 02:02:29 DEBUG : both11: Unchanged skipping 2025/04/19 02:02:29 DEBUG : both1: Unchanged skipping 2025/04/19 02:02:29 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-feyixep3capu': Waiting for checks to finish 2025/04/19 02:02:29 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-feyixep3capu': Waiting for transfers to finish 2025/04/19 02:02:29 DEBUG : Waiting for deletions to finish 2025/04/19 02:02:30 INFO : only10: Deleted 2025/04/19 02:02:30 INFO : only12: Deleted 2025/04/19 02:02:30 INFO : only0: Deleted 2025/04/19 02:02:30 INFO : only6: Deleted 2025/04/19 02:02:30 INFO : only15: Deleted 2025/04/19 02:02:30 INFO : only13: Deleted 2025/04/19 02:02:30 INFO : only19: Deleted 2025/04/19 02:02:30 INFO : only17: Deleted 2025/04/19 02:02:30 INFO : only5: Deleted 2025/04/19 02:02:31 INFO : only8: Deleted 2025/04/19 02:02:31 INFO : only7: Deleted 2025/04/19 02:02:31 INFO : only1: Deleted 2025/04/19 02:02:31 INFO : only18: Deleted 2025/04/19 02:02:31 INFO : only4: Deleted 2025/04/19 02:02:31 INFO : only11: Deleted 2025/04/19 02:02:31 INFO : only14: Deleted 2025/04/19 02:02:31 INFO : only16: Deleted 2025/04/19 02:02:31 INFO : only2: Deleted 2025/04/19 02:02:31 INFO : only3: Deleted 2025/04/19 02:02:32 INFO : only9: Deleted 2025/04/19 02:02:32 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-feyixep3capu'", Local "Local file system at /tmp/rclone3509792376", Modify Window "1ms" --- PASS: TestSyncConcurrentDelete (65.91s) === RUN TestSyncConcurrentTruncate run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-feyixep3capu'", Local "Local file system at /tmp/rclone3509792376", Modify Window "1ms" 2025/04/19 02:02:43 DEBUG : both0: md5 = 96f714cd2b76475d72bb34b28a420594 OK 2025/04/19 02:02:44 DEBUG : only0: md5 = 029f6ee029fca589e7a7e7ee5f39e6c4 OK 2025/04/19 02:02:45 DEBUG : both1: md5 = 5e1ca3610849a3bdd13c1bce514584c5 OK 2025/04/19 02:02:47 DEBUG : only1: md5 = c9f36f82489c549bfe08f893f54dfa53 OK 2025/04/19 02:02:48 DEBUG : both2: md5 = f006191388979e658f555d7ee02def8b OK 2025/04/19 02:02:49 DEBUG : only2: md5 = 5e0e70477a03a223534040e5a5adf049 OK 2025/04/19 02:02:51 DEBUG : both3: md5 = 1c68e1ee0498c9790211f8e178842446 OK 2025/04/19 02:02:52 DEBUG : only3: md5 = c694a2886c06cb8ab0fd5df9f4caddc6 OK 2025/04/19 02:02:53 DEBUG : both4: md5 = 6f2800f54b8644b6471f20fc0888d701 OK 2025/04/19 02:02:55 DEBUG : only4: md5 = f4e7921d83401a5d6d2ea4e0618844bd OK 2025/04/19 02:02:56 DEBUG : both5: md5 = 73e604cab8590588f03cc235b451edc3 OK 2025/04/19 02:02:57 DEBUG : only5: md5 = e300118dfcc35743ca8085cad577a963 OK 2025/04/19 02:02:58 DEBUG : both6: md5 = 4e4993dbac677aaf28a7dfea0b310388 OK 2025/04/19 02:03:00 DEBUG : only6: md5 = e245b669c6cb150ba77b12b59cbb575d OK 2025/04/19 02:03:01 DEBUG : both7: md5 = 64e1c8ea87a14c75ca2b0af43a85eec4 OK 2025/04/19 02:03:02 DEBUG : only7: md5 = 7933558faaa548120552fcba6f7ee677 OK 2025/04/19 02:03:04 DEBUG : both8: md5 = e92b3a1e5ae6cb695955c9f1bc121ce5 OK 2025/04/19 02:03:05 DEBUG : only8: md5 = 50a47f0ec64bcebeede895982381ff7c OK 2025/04/19 02:03:07 DEBUG : both9: md5 = c05a5e89bd5ee0e63306dd6152068b4e OK 2025/04/19 02:03:08 DEBUG : only9: md5 = bea19be4b2a525cc7f868d8e5bd51396 OK 2025/04/19 02:03:09 DEBUG : both10: md5 = 700733cf4981609032e06799cdc9aeff OK 2025/04/19 02:03:11 DEBUG : only10: md5 = a8bbe3eac966c2d91de326424d91f5c0 OK 2025/04/19 02:03:12 DEBUG : both11: md5 = 75ecb7be3596c8d867d59bf73279529b OK 2025/04/19 02:03:13 DEBUG : only11: md5 = e6c5750c7e39d5bfcf01e424882303f7 OK 2025/04/19 02:03:14 DEBUG : both12: md5 = a89c62006af3ddcb5ab5643eeadbbe80 OK 2025/04/19 02:03:16 DEBUG : only12: md5 = 3a3d0b7bd2d3f49298d75b0dc7cda843 OK 2025/04/19 02:03:17 DEBUG : both13: md5 = da16007a4bc46c0b29a49fc82ca5f32a OK 2025/04/19 02:03:18 DEBUG : only13: md5 = e42d417c52b1275a6eaf6239577a082d OK 2025/04/19 02:03:20 DEBUG : both14: md5 = 4f90607df5aa087d84cc5574e2db0277 OK 2025/04/19 02:03:21 DEBUG : only14: md5 = ce20805fa1793be96e8bbd4d3d34c679 OK 2025/04/19 02:03:22 DEBUG : both15: md5 = 4a815544870896d4ed5c7c33c38bff56 OK 2025/04/19 02:03:24 DEBUG : only15: md5 = 55f7dade4b2d5a4c9f850763bac70e9e OK 2025/04/19 02:03:25 DEBUG : both16: md5 = 9fa3aaf0ba286fcfb370e5d7ce63fb33 OK 2025/04/19 02:03:26 DEBUG : only16: md5 = 59e245a72e2215b59cb345f5ceedb0f0 OK 2025/04/19 02:03:28 DEBUG : both17: md5 = c6fc941f8f5cad9e7841ee7ed79ba5a2 OK 2025/04/19 02:03:29 DEBUG : only17: md5 = 9d0cc261c3704336c33680a4ba15af17 OK 2025/04/19 02:03:30 DEBUG : both18: md5 = 94d64345cb36a261fb8de4cc654c4d0d OK 2025/04/19 02:03:32 DEBUG : only18: md5 = d685756d6cd7ce1ed47e93ffaad02c30 OK 2025/04/19 02:03:33 DEBUG : both19: md5 = afa8573130bc0c3d481b7cd4df51f144 OK 2025/04/19 02:03:34 DEBUG : only19: md5 = 5cbcb195c51b74f1761ab471bcae29d7 OK 2025/04/19 02:03:35 DEBUG : both0: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/19 02:03:35 DEBUG : both1: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/19 02:03:35 DEBUG : both11: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/19 02:03:35 DEBUG : both10: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/19 02:03:35 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-feyixep3capu': Waiting for checks to finish 2025/04/19 02:03:35 DEBUG : both0: Unchanged skipping 2025/04/19 02:03:35 DEBUG : both12: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/19 02:03:35 DEBUG : both12: Unchanged skipping 2025/04/19 02:03:35 DEBUG : both13: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/19 02:03:35 DEBUG : both13: Unchanged skipping 2025/04/19 02:03:35 DEBUG : both14: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/19 02:03:35 DEBUG : both14: Unchanged skipping 2025/04/19 02:03:35 DEBUG : both15: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/19 02:03:35 DEBUG : both15: Unchanged skipping 2025/04/19 02:03:35 DEBUG : both16: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/19 02:03:35 DEBUG : both16: Unchanged skipping 2025/04/19 02:03:35 DEBUG : both17: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/19 02:03:35 DEBUG : both17: Unchanged skipping 2025/04/19 02:03:35 DEBUG : both18: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/19 02:03:35 DEBUG : both18: Unchanged skipping 2025/04/19 02:03:35 DEBUG : both19: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/19 02:03:35 DEBUG : both10: Unchanged skipping 2025/04/19 02:03:35 DEBUG : both2: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/19 02:03:35 DEBUG : both2: Unchanged skipping 2025/04/19 02:03:35 DEBUG : both3: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/19 02:03:35 DEBUG : both3: Unchanged skipping 2025/04/19 02:03:35 DEBUG : both4: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/19 02:03:35 DEBUG : both4: Unchanged skipping 2025/04/19 02:03:35 DEBUG : both5: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/19 02:03:35 DEBUG : both5: Unchanged skipping 2025/04/19 02:03:35 DEBUG : both6: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/19 02:03:35 DEBUG : both6: Unchanged skipping 2025/04/19 02:03:35 DEBUG : both7: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/19 02:03:35 DEBUG : both7: Unchanged skipping 2025/04/19 02:03:35 DEBUG : both8: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/19 02:03:35 DEBUG : both8: Unchanged skipping 2025/04/19 02:03:35 DEBUG : both9: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/19 02:03:35 DEBUG : both1: Unchanged skipping 2025/04/19 02:03:35 DEBUG : only0: Sizes differ (src 0 vs dst 6) 2025/04/19 02:03:35 DEBUG : both19: Unchanged skipping 2025/04/19 02:03:35 DEBUG : only1: Sizes differ (src 0 vs dst 6) 2025/04/19 02:03:35 DEBUG : both11: Unchanged skipping 2025/04/19 02:03:35 DEBUG : only10: Sizes differ (src 0 vs dst 6) 2025/04/19 02:03:35 DEBUG : both9: Unchanged skipping 2025/04/19 02:03:35 DEBUG : only11: Sizes differ (src 0 vs dst 6) 2025/04/19 02:03:35 DEBUG : only12: Sizes differ (src 0 vs dst 6) 2025/04/19 02:03:35 DEBUG : only13: Sizes differ (src 0 vs dst 6) 2025/04/19 02:03:35 DEBUG : only14: Sizes differ (src 0 vs dst 6) 2025/04/19 02:03:35 DEBUG : only15: Sizes differ (src 0 vs dst 6) 2025/04/19 02:03:35 DEBUG : only16: Sizes differ (src 0 vs dst 6) 2025/04/19 02:03:35 DEBUG : only17: Sizes differ (src 0 vs dst 6) 2025/04/19 02:03:35 DEBUG : only18: Sizes differ (src 0 vs dst 6) 2025/04/19 02:03:35 DEBUG : only19: Sizes differ (src 0 vs dst 6) 2025/04/19 02:03:35 DEBUG : only2: Sizes differ (src 0 vs dst 6) 2025/04/19 02:03:35 DEBUG : only3: Sizes differ (src 0 vs dst 6) 2025/04/19 02:03:35 DEBUG : only4: Sizes differ (src 0 vs dst 6) 2025/04/19 02:03:35 DEBUG : only5: Sizes differ (src 0 vs dst 6) 2025/04/19 02:03:35 DEBUG : only7: Sizes differ (src 0 vs dst 6) 2025/04/19 02:03:35 DEBUG : only6: Sizes differ (src 0 vs dst 6) 2025/04/19 02:03:35 DEBUG : only8: Sizes differ (src 0 vs dst 6) 2025/04/19 02:03:35 DEBUG : only9: Sizes differ (src 0 vs dst 6) 2025/04/19 02:03:35 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-feyixep3capu': Waiting for transfers to finish 2025/04/19 02:03:36 DEBUG : only11: md5 = f45b6c79bedea0b4e83881f3110506ae OK 2025/04/19 02:03:36 INFO : only11: Copied (replaced existing) 2025/04/19 02:03:36 DEBUG : only13: md5 = d58c73b62165a9cc0f7a6132dd182268 OK 2025/04/19 02:03:36 INFO : only13: Copied (replaced existing) 2025/04/19 02:03:36 DEBUG : only14: md5 = 468dd61d346712a5f0d477985a74ab37 OK 2025/04/19 02:03:36 INFO : only14: Copied (replaced existing) 2025/04/19 02:03:36 DEBUG : only12: md5 = 18f4be7057b3d674450fee22651bae97 OK 2025/04/19 02:03:36 INFO : only12: Copied (replaced existing) 2025/04/19 02:03:37 DEBUG : only15: md5 = 994bc12e287b385ad0c2bc272d07c1ed OK 2025/04/19 02:03:37 INFO : only15: Copied (replaced existing) 2025/04/19 02:03:37 DEBUG : only0: md5 = 4c5d4a3111514e41f1ae12ade5907fda OK 2025/04/19 02:03:37 INFO : only0: Copied (replaced existing) 2025/04/19 02:03:37 DEBUG : only1: md5 = d304a3ac0d1fa69e984856971bd89ef4 OK 2025/04/19 02:03:37 INFO : only1: Copied (replaced existing) 2025/04/19 02:03:37 DEBUG : only16: md5 = 6fbb2d4d04e0b8c41897cee52f9fadfd OK 2025/04/19 02:03:37 INFO : only16: Copied (replaced existing) 2025/04/19 02:03:38 DEBUG : only10: md5 = 7dac6a0af6b3cd688edb792e03190d3b OK 2025/04/19 02:03:38 INFO : only10: Copied (replaced existing) 2025/04/19 02:03:38 DEBUG : only18: md5 = 098485c2dbd5fbdb1ee106ba68dd6f33 OK 2025/04/19 02:03:38 INFO : only18: Copied (replaced existing) 2025/04/19 02:03:38 DEBUG : only17: md5 = cdb3e07a5776e7010a9fe6118e9e02f9 OK 2025/04/19 02:03:38 INFO : only17: Copied (replaced existing) 2025/04/19 02:03:38 DEBUG : only3: md5 = a8c3d27d4ca9774a8461d17c4f7eb319 OK 2025/04/19 02:03:38 INFO : only3: Copied (replaced existing) 2025/04/19 02:03:39 DEBUG : only19: md5 = ae2f48fd2d3bb3b40b584da4f2bc6136 OK 2025/04/19 02:03:39 INFO : only19: Copied (replaced existing) 2025/04/19 02:03:39 DEBUG : only5: md5 = 7be8a327c9284823c755b33ce0317bf1 OK 2025/04/19 02:03:39 INFO : only5: Copied (replaced existing) 2025/04/19 02:03:39 DEBUG : only4: md5 = 8b7198476de274003082a4f7e6fd4ace OK 2025/04/19 02:03:39 INFO : only4: Copied (replaced existing) 2025/04/19 02:03:39 DEBUG : only2: md5 = d5db998f4d35567f957ac6c19eca7e35 OK 2025/04/19 02:03:39 INFO : only2: Copied (replaced existing) 2025/04/19 02:03:40 DEBUG : only7: md5 = 99717dbbd376c836482156530b172d9d OK 2025/04/19 02:03:40 INFO : only7: Copied (replaced existing) 2025/04/19 02:03:40 DEBUG : only6: md5 = e81556951376dc8009344a6ca7ed2504 OK 2025/04/19 02:03:40 INFO : only6: Copied (replaced existing) 2025/04/19 02:03:40 DEBUG : only9: md5 = 564eceee54b544e0f6ced271eaa16b4c OK 2025/04/19 02:03:40 INFO : only9: Copied (replaced existing) 2025/04/19 02:03:41 DEBUG : only8: md5 = fcbb100827a7be0fdb4c84e80ad07460 OK 2025/04/19 02:03:41 INFO : only8: Copied (replaced existing) 2025/04/19 02:03:41 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-feyixep3capu'", Local "Local file system at /tmp/rclone3509792376", Modify Window "1ms" --- PASS: TestSyncConcurrentTruncate (77.49s) === RUN TestSyncReplaceDirModTime run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-feyixep3capu'", Local "Local file system at /tmp/rclone3509792376", Modify Window "1ms" 2025/04/19 02:03:59 DEBUG : empty_dir: Making directory with metadata 2025/04/19 02:03:59 INFO : empty_dir: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2025/04/19 02:03:59 DEBUG : empty_on_remote: Making directory with metadata 2025/04/19 02:03:59 INFO : empty_on_remote: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2025/04/19 02:03:59 DEBUG : empty_on_remote: Making directory with metadata 2025/04/19 02:04:00 INFO : empty_on_remote: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-feyixep3capu'", Local "Local file system at /tmp/rclone3509792376", Modify Window "1ms" 2025/04/19 02:04:05 INFO : test_dir1: Set directory modification time (using DirSetModTime) 2025/04/19 02:04:05 INFO : test_dir2: Set directory modification time (using DirSetModTime) 2025/04/19 02:04:05 INFO : test_dir2/sub_dir: Set directory modification time (using DirSetModTime) 2025/04/19 02:04:05 INFO : empty_on_remote: Set directory modification time (using DirSetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-feyixep3capu'", Local "Local file system at /tmp/rclone3509792376", Modify Window "1ms" 2025/04/19 02:04:11 DEBUG : heqj02jg0dcqlem7gl0500bvp0/24g2k8bseitblkmqnie1ibl2s8: Rmdir: contains trashed file: "633fmaa0qic3kv3cladnu11pto" 2025/04/19 02:04:12 DEBUG : heqj02jg0dcqlem7gl0500bvp0: Rmdir: contains trashed file: "24g2k8bseitblkmqnie1ibl2s8" 2025/04/19 02:04:13 DEBUG : gq68srrpl0nnf394bgf7dbu9kc: Rmdir: contains trashed file: "d26uovf0miqhd1mu3c9jbseq00" --- PASS: TestSyncReplaceDirModTime (15.90s) === RUN TestSyncReplaceDirModTimeWithEmptyDirs run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-feyixep3capu'", Local "Local file system at /tmp/rclone3509792376", Modify Window "1ms" 2025/04/19 02:04:15 DEBUG : empty_dir: Making directory with metadata 2025/04/19 02:04:15 INFO : empty_dir: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2025/04/19 02:04:15 DEBUG : empty_on_remote: Making directory with metadata 2025/04/19 02:04:15 INFO : empty_on_remote: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2025/04/19 02:04:15 DEBUG : empty_on_remote: Making directory with metadata 2025/04/19 02:04:15 INFO : empty_on_remote: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-feyixep3capu'", Local "Local file system at /tmp/rclone3509792376", Modify Window "1ms" 2025/04/19 02:04:20 INFO : test_dir1: Set directory modification time (using DirSetModTime) 2025/04/19 02:04:20 INFO : test_dir2: Set directory modification time (using DirSetModTime) 2025/04/19 02:04:20 INFO : test_dir2/sub_dir: Set directory modification time (using DirSetModTime) 2025/04/19 02:04:20 INFO : empty_on_remote: Set directory modification time (using DirSetModTime) 2025/04/19 02:04:20 INFO : empty_dir: Set directory modification time (using DirSetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-feyixep3capu'", Local "Local file system at /tmp/rclone3509792376", Modify Window "1ms" 2025/04/19 02:04:27 DEBUG : heqj02jg0dcqlem7gl0500bvp0/24g2k8bseitblkmqnie1ibl2s8: Rmdir: contains trashed file: "633fmaa0qic3kv3cladnu11pto" 2025/04/19 02:04:28 DEBUG : heqj02jg0dcqlem7gl0500bvp0: Rmdir: contains trashed file: "24g2k8bseitblkmqnie1ibl2s8" 2025/04/19 02:04:29 DEBUG : gq68srrpl0nnf394bgf7dbu9kc: Rmdir: contains trashed file: "d26uovf0miqhd1mu3c9jbseq00" --- PASS: TestSyncReplaceDirModTimeWithEmptyDirs (16.74s) === RUN TestNothingToTransferWithEmptyDirs run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-feyixep3capu'", Local "Local file system at /tmp/rclone3509792376", Modify Window "1ms" 2025/04/19 02:04:32 INFO : sub dir: Set directory modification time (using DirSetModTime) 2025/04/19 02:04:32 DEBUG : sub dir: Making directory with metadata 2025/04/19 02:04:32 INFO : sub dir: Made directory with metadata (mtime=2011-12-30T12:59:59Z) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-feyixep3capu'", Local "Local file system at /tmp/rclone3509792376", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-feyixep3capu'", Local "Local file system at /tmp/rclone3509792376", Modify Window "1ms" 2025/04/19 02:04:49 INFO : sub dir2: Set directory modification time (using DirSetModTime) 2025/04/19 02:04:49 INFO : sub dir2: Set directory modification time (using DirSetModTime) 2025/04/19 02:04:49 INFO : sub dirEmpty/sub dirEmpty2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2025/04/19 02:04:49 INFO : sub dirEmpty: Set directory modification time (using DirSetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-feyixep3capu'", Local "Local file system at /tmp/rclone3509792376", Modify Window "1ms" 2025/04/19 02:05:03 DEBUG : gcsdkq814sbtppue42dpsbg8ug: Rmdir: contains trashed file: "sjuo65gk5q3r1199jselk9k9o0" 2025/04/19 02:05:03 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/37qp6d1gohacv723ij3brofbu8/i24n0ln37pa2hv8pctddeuh73o: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" 2025/04/19 02:05:04 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/37qp6d1gohacv723ij3brofbu8: Rmdir: contains trashed file: "i24n0ln37pa2hv8pctddeuh73o" 2025/04/19 02:05:05 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "37qp6d1gohacv723ij3brofbu8" 2025/04/19 02:05:05 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak" 2025/04/19 02:05:06 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak" 2025/04/19 02:05:07 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak" 2025/04/19 02:05:07 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak" 2025/04/19 02:05:08 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/4r13oncfa2rsrr82oqhsqv24ns: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" 2025/04/19 02:05:09 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc: Rmdir: contains trashed file: "4r13oncfa2rsrr82oqhsqv24ns" 2025/04/19 02:05:09 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak" 2025/04/19 02:05:10 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestNothingToTransferWithEmptyDirs (40.23s) === RUN TestNothingToTransferWithoutEmptyDirs run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-feyixep3capu'", Local "Local file system at /tmp/rclone3509792376", Modify Window "1ms" 2025/04/19 02:05:12 INFO : sub dir: Set directory modification time (using DirSetModTime) 2025/04/19 02:05:12 DEBUG : sub dir: Making directory with metadata 2025/04/19 02:05:12 INFO : sub dir: Made directory with metadata (mtime=2011-12-30T12:59:59Z) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-feyixep3capu'", Local "Local file system at /tmp/rclone3509792376", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-feyixep3capu'", Local "Local file system at /tmp/rclone3509792376", Modify Window "1ms" 2025/04/19 02:05:33 INFO : sub dir2: Set directory modification time (using DirSetModTime) 2025/04/19 02:05:34 INFO : sub dir2: Set directory modification time (using DirSetModTime) 2025/04/19 02:05:34 INFO : sub dirEmpty/sub dirEmpty2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2025/04/19 02:05:34 INFO : sub dirEmpty: Set directory modification time (using DirSetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-feyixep3capu'", Local "Local file system at /tmp/rclone3509792376", Modify Window "1ms" 2025/04/19 02:05:46 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/37qp6d1gohacv723ij3brofbu8/i24n0ln37pa2hv8pctddeuh73o: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" 2025/04/19 02:05:46 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/37qp6d1gohacv723ij3brofbu8: Rmdir: contains trashed file: "i24n0ln37pa2hv8pctddeuh73o" 2025/04/19 02:05:47 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "37qp6d1gohacv723ij3brofbu8" 2025/04/19 02:05:48 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak" 2025/04/19 02:05:48 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak" 2025/04/19 02:05:49 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak" 2025/04/19 02:05:50 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak" 2025/04/19 02:05:50 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/4r13oncfa2rsrr82oqhsqv24ns: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" 2025/04/19 02:05:51 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc: Rmdir: contains trashed file: "4r13oncfa2rsrr82oqhsqv24ns" 2025/04/19 02:05:51 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak" 2025/04/19 02:05:52 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestNothingToTransferWithoutEmptyDirs (42.10s) PASS 2025/04/19 02:05:54 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-feyixep3capu': Purge remote "./sync.test -test.v -test.timeout 1h0m0s -remote TestCryptDrive: -verbose -fast-list" - Finished OK in 15m2.057286952s (try 1/5)