"./sync.test -test.v -test.timeout 1h0m0s -remote TestCryptDrive: -verbose" - Starting (try 1/5) 2025/02/13 04:25:01 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-cehowil2kivu" 2025/02/13 04:25:01 DEBUG : Using config file from "/home/rclone/.rclone.conf" 2025/02/13 04:25:01 DEBUG : Creating backend with remote "TestDrive:crypt/2taekpjjreop3k6cmt0r4mp4qbpg9lhqqk3ep1qfmvlh1ctr5r5g" 2025/02/13 04:25:01 DEBUG : TestDrive: Loaded invalid token from config file - ignoring 2025/02/13 04:25:01 DEBUG : Saving config "token" in section "TestDrive" of the config file 2025/02/13 04:25:01 DEBUG : TestDrive: Saved new token in config file 2025/02/13 04:25:02 DEBUG : Creating backend with remote "/tmp/rclone251320568" === RUN TestPipe --- PASS: TestPipe (0.00s) === RUN TestPipeConcurrent --- PASS: TestPipeConcurrent (0.02s) === 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-cehowil2kivu'", Local "Local file system at /tmp/rclone251320568", Modify Window "1ms" 2025/02/13 04:25:03 DEBUG : Added delayed dir = "sub dir", newDst= 2025/02/13 04:25:03 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2025/02/13 04:25:03 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-cehowil2kivu': Waiting for checks to finish 2025/02/13 04:25:03 NOTICE: sub dir/hello world: Skipped copy as --dry-run is set (size 11) 2025/02/13 04:25:03 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-cehowil2kivu': Waiting for transfers to finish 2025/02/13 04:25:03 NOTICE: sub dir: Skipped set directory modification time as --dry-run is set run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-cehowil2kivu'", Local "Local file system at /tmp/rclone251320568", Modify Window "1ms" --- PASS: TestCopyWithDryRun (2.37s) === RUN TestCopy run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-cehowil2kivu'", Local "Local file system at /tmp/rclone251320568", Modify Window "1ms" 2025/02/13 04:25:05 INFO : sub dir: Set directory modification time (using DirSetModTime) 2025/02/13 04:25:05 DEBUG : Added delayed dir = "sub dir", newDst= 2025/02/13 04:25:05 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2025/02/13 04:25:05 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-cehowil2kivu': Waiting for checks to finish 2025/02/13 04:25:05 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-cehowil2kivu': Waiting for transfers to finish 2025/02/13 04:25:07 DEBUG : sub dir/hello world: md5 = 7f4cf1d2ada37d8420b116de3cc21121 OK 2025/02/13 04:25:07 INFO : sub dir/hello world: Copied (new) 2025/02/13 04:25:08 INFO : sub dir: Set directory modification time (using DirSetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-cehowil2kivu'", Local "Local file system at /tmp/rclone251320568", Modify Window "1ms" 2025/02/13 04:25:10 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestCopy (6.36s) === RUN TestCopyMetadata run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-cehowil2kivu'", Local "Local file system at /tmp/rclone251320568", Modify Window "1ms" 2025/02/13 04:25:11 DEBUG : metadata sub dir: Making directory with metadata 2025/02/13 04:25:11 INFO : metadata sub dir: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2025/02/13 04:25:11 DEBUG : empty metadata sub dir: Making directory with metadata 2025/02/13 04:25:11 INFO : empty metadata sub dir: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2025/02/13 04:25:11 DEBUG : Local file system at /tmp/rclone251320568: File to upload is small (21 bytes), uploading instead of streaming 2025/02/13 04:25:11 DEBUG : metadata sub dir/hello metadata world: md5 = baa7a013449dbba2b1ed02b5cfb4e1a2 OK 2025/02/13 04:25:11 DEBUG : metadata sub dir/hello metadata world: Size and md5 of src and dst objects identical 2025/02/13 04:25:11 INFO : metadata sub dir: Set directory modification time (using DirSetModTime) 2025/02/13 04:25:11 DEBUG : Google drive root 'crypt/2taekpjjreop3k6cmt0r4mp4qbpg9lhqqk3ep1qfmvlh1ctr5r5g': Skipping btime metadata as can't update it on an existing file: 2025-02-13T04:25:11.512507467Z 2025/02/13 04:25:12 INFO : empty metadata sub dir: Updated directory metadata 2025/02/13 04:25:12 DEBUG : Google drive root 'crypt/2taekpjjreop3k6cmt0r4mp4qbpg9lhqqk3ep1qfmvlh1ctr5r5g': Skipping btime metadata as can't update it on an existing file: 2025-02-13T04:25:11.512507467Z 2025/02/13 04:25:13 INFO : metadata sub dir: Updated directory metadata 2025/02/13 04:25:13 DEBUG : metadata sub dir/hello metadata world: Need to transfer - File not found at Destination 2025/02/13 04:25:13 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-cehowil2kivu': Waiting for checks to finish 2025/02/13 04:25:13 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-cehowil2kivu': Waiting for transfers to finish 2025/02/13 04:25:15 DEBUG : metadata sub dir/hello metadata world: md5 = 1dc0e6ecabe4d5121dc9cecf432fcbbe OK 2025/02/13 04:25:15 INFO : metadata sub dir/hello metadata world: Copied (new) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-cehowil2kivu'", Local "Local file system at /tmp/rclone251320568", Modify Window "1ms" 2025/02/13 04:25:18 DEBUG : fg45q1rm3kh00nmmkk4m6ihmrcnel1p7551kqhjr9bk2gtd2gbf0: Rmdir: contains trashed file: "dmuvulfij81f693ur0f1vvbvq9v6iscp56daas3m51n9li5e3470" --- PASS: TestCopyMetadata (8.84s) === RUN TestCopyMetadataNoEmptyDirs run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-cehowil2kivu'", Local "Local file system at /tmp/rclone251320568", Modify Window "1ms" 2025/02/13 04:25:20 DEBUG : metadata sub dir: Making directory with metadata 2025/02/13 04:25:20 INFO : metadata sub dir: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2025/02/13 04:25:20 DEBUG : empty metadata sub dir: Making directory with metadata 2025/02/13 04:25:20 INFO : empty metadata sub dir: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2025/02/13 04:25:20 DEBUG : Local file system at /tmp/rclone251320568: File to upload is small (21 bytes), uploading instead of streaming 2025/02/13 04:25:20 DEBUG : metadata sub dir/hello metadata world: md5 = baa7a013449dbba2b1ed02b5cfb4e1a2 OK 2025/02/13 04:25:20 DEBUG : metadata sub dir/hello metadata world: Size and md5 of src and dst objects identical 2025/02/13 04:25:20 INFO : metadata sub dir: Set directory modification time (using DirSetModTime) 2025/02/13 04:25:20 DEBUG : Added delayed dir = "empty metadata sub dir", newDst= 2025/02/13 04:25:20 DEBUG : Added delayed dir = "metadata sub dir", newDst= 2025/02/13 04:25:20 DEBUG : metadata sub dir/hello metadata world: Need to transfer - File not found at Destination 2025/02/13 04:25:20 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-cehowil2kivu': Waiting for checks to finish 2025/02/13 04:25:20 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-cehowil2kivu': Waiting for transfers to finish 2025/02/13 04:25:22 DEBUG : metadata sub dir/hello metadata world: md5 = 1567533a3fdabd90684c20ebb3c7cd1b OK 2025/02/13 04:25:22 INFO : metadata sub dir/hello metadata world: Copied (new) 2025/02/13 04:25:22 DEBUG : Google drive root 'crypt/2taekpjjreop3k6cmt0r4mp4qbpg9lhqqk3ep1qfmvlh1ctr5r5g': Skipping btime metadata as can't update it on an existing file: 2025-02-13T04:25:20.356443321Z 2025/02/13 04:25:23 INFO : metadata sub dir: Updated directory metadata run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-cehowil2kivu'", Local "Local file system at /tmp/rclone251320568", Modify Window "1ms" 2025/02/13 04:25:26 DEBUG : fg45q1rm3kh00nmmkk4m6ihmrcnel1p7551kqhjr9bk2gtd2gbf0: Rmdir: contains trashed file: "dmuvulfij81f693ur0f1vvbvq9v6iscp56daas3m51n9li5e3470" --- PASS: TestCopyMetadataNoEmptyDirs (7.18s) === RUN TestCopyMissingDirectory run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-cehowil2kivu'", Local "Local file system at /tmp/rclone251320568", Modify Window "1ms" 2025/02/13 04:25:27 DEBUG : Creating backend with remote "/non-existing" 2025/02/13 04:25:27 ERROR : Local file system at /non-existing: error reading source root directory: directory not found 2025/02/13 04:25:27 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-cehowil2kivu': Waiting for checks to finish 2025/02/13 04:25:27 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-cehowil2kivu': Waiting for transfers to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-cehowil2kivu'", Local "Local file system at /tmp/rclone251320568", Modify Window "1ms" --- PASS: TestCopyMissingDirectory (1.24s) === RUN TestCopyNoTraverse run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-cehowil2kivu'", Local "Local file system at /tmp/rclone251320568", Modify Window "1ms" 2025/02/13 04:25:28 DEBUG : Added delayed dir = "sub dir", newDst= 2025/02/13 04:25:29 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2025/02/13 04:25:29 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-cehowil2kivu': Waiting for checks to finish 2025/02/13 04:25:29 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-cehowil2kivu': Waiting for transfers to finish 2025/02/13 04:25:31 DEBUG : sub dir/hello world: md5 = f47e5a961bef62bd66838ff447283303 OK 2025/02/13 04:25:31 INFO : sub dir/hello world: Copied (new) 2025/02/13 04:25:31 INFO : sub dir: Set directory modification time (using DirSetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-cehowil2kivu'", Local "Local file system at /tmp/rclone251320568", Modify Window "1ms" 2025/02/13 04:25:33 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestCopyNoTraverse (6.09s) === RUN TestCopyCheckFirst run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-cehowil2kivu'", Local "Local file system at /tmp/rclone251320568", Modify Window "1ms" 2025/02/13 04:25:34 INFO : Encrypted drive 'TestCryptDrive:rclone-test-cehowil2kivu': Running all checks before starting transfers 2025/02/13 04:25:35 DEBUG : Added delayed dir = "sub dir", newDst= 2025/02/13 04:25:35 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2025/02/13 04:25:35 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-cehowil2kivu': Waiting for checks to finish 2025/02/13 04:25:35 INFO : Encrypted drive 'TestCryptDrive:rclone-test-cehowil2kivu': Checks finished, now starting transfers 2025/02/13 04:25:35 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-cehowil2kivu': Waiting for transfers to finish 2025/02/13 04:25:37 DEBUG : sub dir/hello world: md5 = 7a9d4bf025fb29a5a42b7aaa22c4c1bc OK 2025/02/13 04:25:37 INFO : sub dir/hello world: Copied (new) 2025/02/13 04:25:37 INFO : sub dir: Set directory modification time (using DirSetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-cehowil2kivu'", Local "Local file system at /tmp/rclone251320568", Modify Window "1ms" 2025/02/13 04:25:39 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestCopyCheckFirst (5.66s) === RUN TestSyncNoTraverse run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-cehowil2kivu'", Local "Local file system at /tmp/rclone251320568", Modify Window "1ms" 2025/02/13 04:25:40 ERROR : Ignoring --no-traverse with sync 2025/02/13 04:25:40 DEBUG : Added delayed dir = "sub dir", newDst= 2025/02/13 04:25:40 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2025/02/13 04:25:40 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-cehowil2kivu': Waiting for checks to finish 2025/02/13 04:25:40 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-cehowil2kivu': Waiting for transfers to finish 2025/02/13 04:25:43 DEBUG : sub dir/hello world: md5 = 414c18ec5146a5faba0a00759c93c777 OK 2025/02/13 04:25:43 INFO : sub dir/hello world: Copied (new) 2025/02/13 04:25:43 DEBUG : Waiting for deletions to finish 2025/02/13 04:25:43 INFO : sub dir: Set directory modification time (using DirSetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-cehowil2kivu'", Local "Local file system at /tmp/rclone251320568", Modify Window "1ms" 2025/02/13 04:25:45 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestSyncNoTraverse (6.22s) === RUN TestCopyWithDepth run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-cehowil2kivu'", Local "Local file system at /tmp/rclone251320568", Modify Window "1ms" 2025/02/13 04:25:46 DEBUG : hello world2: Need to transfer - File not found at Destination 2025/02/13 04:25:46 DEBUG : Added delayed dir = "sub dir", newDst= 2025/02/13 04:25:46 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-cehowil2kivu': Waiting for checks to finish 2025/02/13 04:25:46 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-cehowil2kivu': Waiting for transfers to finish 2025/02/13 04:25:48 DEBUG : hello world2: md5 = fc1cdfb3c74dc117e2618aea9174a311 OK 2025/02/13 04:25:48 INFO : hello world2: Copied (new) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-cehowil2kivu'", Local "Local file system at /tmp/rclone251320568", Modify Window "1ms" --- PASS: TestCopyWithDepth (3.38s) === RUN TestCopyWithFilesFrom run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-cehowil2kivu'", Local "Local file system at /tmp/rclone251320568", Modify Window "1ms" 2025/02/13 04:25:50 DEBUG : potato2: Need to transfer - File not found at Destination 2025/02/13 04:25:50 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-cehowil2kivu': Waiting for checks to finish 2025/02/13 04:25:50 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-cehowil2kivu': Waiting for transfers to finish 2025/02/13 04:25:51 DEBUG : potato2: md5 = 3f039bee2dbae1bf20698c8a0b3fd76a OK 2025/02/13 04:25:51 INFO : potato2: Copied (new) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-cehowil2kivu'", Local "Local file system at /tmp/rclone251320568", Modify Window "1ms" --- PASS: TestCopyWithFilesFrom (3.51s) === RUN TestCopyWithFilesFromAndNoTraverse run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-cehowil2kivu'", Local "Local file system at /tmp/rclone251320568", Modify Window "1ms" 2025/02/13 04:25:53 DEBUG : potato2: Need to transfer - File not found at Destination 2025/02/13 04:25:53 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-cehowil2kivu': Waiting for checks to finish 2025/02/13 04:25:53 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-cehowil2kivu': Waiting for transfers to finish 2025/02/13 04:25:55 DEBUG : potato2: md5 = 3841e8da4e92545ef55a2ed97e7a55a2 OK 2025/02/13 04:25:55 INFO : potato2: Copied (new) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-cehowil2kivu'", Local "Local file system at /tmp/rclone251320568", Modify Window "1ms" --- PASS: TestCopyWithFilesFromAndNoTraverse (3.48s) === RUN TestCopyEmptyDirectories run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-cehowil2kivu'", Local "Local file system at /tmp/rclone251320568", Modify Window "1ms" 2025/02/13 04:25:57 DEBUG : sub dir2/sub sub dir2: Making directory with metadata 2025/02/13 04:25:57 INFO : sub dir2/sub sub dir2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2025/02/13 04:25:57 INFO : sub dir2: Set directory modification time (using DirSetModTime) 2025/02/13 04:25:57 INFO : sub dir: Set directory modification time (using DirSetModTime) 2025/02/13 04:25:57 DEBUG : sub dir: Making directory with metadata 2025/02/13 04:25:58 INFO : sub dir: Made directory with metadata (mtime=2001-02-03T04:05:06.499999999Z) 2025/02/13 04:25:58 DEBUG : sub dir2: Making directory with metadata 2025/02/13 04:25:58 INFO : sub dir2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2025/02/13 04:25:58 DEBUG : sub dir2/sub sub dir2: Making directory with metadata 2025/02/13 04:25:58 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2025/02/13 04:25:59 INFO : sub dir2/sub sub dir2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2025/02/13 04:25:59 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-cehowil2kivu': Waiting for checks to finish 2025/02/13 04:25:59 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-cehowil2kivu': Waiting for transfers to finish 2025/02/13 04:26:00 DEBUG : sub dir/hello world: md5 = 85f17e3d08397380973c7cf0557d1b21 OK 2025/02/13 04:26:00 INFO : sub dir/hello world: Copied (new) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-cehowil2kivu'", Local "Local file system at /tmp/rclone251320568", Modify Window "1ms" 2025/02/13 04:26:04 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc: Rmdir: contains trashed file: "cv6a9uf28ngrajena8kt5ijjn0" 2025/02/13 04:26:05 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestCopyEmptyDirectories (9.19s) === RUN TestCopyNoEmptyDirectories run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-cehowil2kivu'", Local "Local file system at /tmp/rclone251320568", Modify Window "1ms" 2025/02/13 04:26:06 INFO : sub dir2: Making directory 2025/02/13 04:26:06 DEBUG : sub dir2/sub sub dir2: Making directory with metadata 2025/02/13 04:26:06 INFO : sub dir2/sub sub dir2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2025/02/13 04:26:06 DEBUG : Added delayed dir = "sub dir", newDst= 2025/02/13 04:26:06 DEBUG : Added delayed dir = "sub dir2", newDst= 2025/02/13 04:26:06 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2025/02/13 04:26:06 DEBUG : Added delayed dir = "sub dir2/sub sub dir2", newDst= 2025/02/13 04:26:06 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-cehowil2kivu': Waiting for checks to finish 2025/02/13 04:26:06 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-cehowil2kivu': Waiting for transfers to finish 2025/02/13 04:26:08 DEBUG : sub dir/hello world: md5 = 21c561b043fabf5458d548d07baccad2 OK 2025/02/13 04:26:08 INFO : sub dir/hello world: Copied (new) 2025/02/13 04:26:09 INFO : sub dir: Set directory modification time (using DirSetModTime) 2025/02/13 04:26:11 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestCopyNoEmptyDirectories (5.58s) === RUN TestMoveEmptyDirectories run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-cehowil2kivu'", Local "Local file system at /tmp/rclone251320568", Modify Window "1ms" 2025/02/13 04:26:11 DEBUG : sub dir2: Making directory with metadata 2025/02/13 04:26:11 INFO : sub dir2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2025/02/13 04:26:12 DEBUG : sub dir: Making directory with metadata 2025/02/13 04:26:12 INFO : sub dir: Made directory with metadata (mtime=2025-02-13T04:26:11.880070717Z) 2025/02/13 04:26:12 DEBUG : sub dir2: Making directory with metadata 2025/02/13 04:26:13 INFO : sub dir2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2025/02/13 04:26:13 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2025/02/13 04:26:13 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-cehowil2kivu': Waiting for checks to finish 2025/02/13 04:26:13 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-cehowil2kivu': Waiting for transfers to finish 2025/02/13 04:26:15 DEBUG : sub dir/hello world: md5 = a1e5a4d8357b5837012a8302845d9433 OK 2025/02/13 04:26:15 INFO : sub dir/hello world: Copied (new) 2025/02/13 04:26:15 INFO : sub dir/hello world: Deleted run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-cehowil2kivu'", Local "Local file system at /tmp/rclone251320568", Modify Window "1ms" 2025/02/13 04:26:17 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestMoveEmptyDirectories (7.33s) === RUN TestSyncNoUpdateDirModtime run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-cehowil2kivu'", Local "Local file system at /tmp/rclone251320568", Modify Window "1ms" 2025/02/13 04:26:19 DEBUG : sub dir no update dir modtime: Making directory with metadata 2025/02/13 04:26:19 INFO : sub dir no update dir modtime: Made directory with metadata (mtime=2001-02-03T04:05:06.499999999Z) 2025/02/13 04:26:20 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-cehowil2kivu': Waiting for checks to finish 2025/02/13 04:26:20 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-cehowil2kivu': Waiting for transfers to finish 2025/02/13 04:26:20 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-cehowil2kivu'", Local "Local file system at /tmp/rclone251320568", Modify Window "1ms" --- PASS: TestSyncNoUpdateDirModtime (4.04s) === RUN TestMoveNoEmptyDirectories run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-cehowil2kivu'", Local "Local file system at /tmp/rclone251320568", Modify Window "1ms" 2025/02/13 04:26:23 INFO : sub dir2: Making directory 2025/02/13 04:26:23 DEBUG : Added delayed dir = "sub dir", newDst= 2025/02/13 04:26:23 DEBUG : Added delayed dir = "sub dir2", newDst= 2025/02/13 04:26:23 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2025/02/13 04:26:23 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-cehowil2kivu': Waiting for checks to finish 2025/02/13 04:26:23 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-cehowil2kivu': Waiting for transfers to finish 2025/02/13 04:26:25 DEBUG : sub dir/hello world: md5 = 7943287af13d239dca95e2e767284aa4 OK 2025/02/13 04:26:25 INFO : sub dir/hello world: Copied (new) 2025/02/13 04:26:25 INFO : sub dir/hello world: Deleted 2025/02/13 04:26:26 INFO : sub dir: Set directory modification time (using DirSetModTime) 2025/02/13 04:26:28 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestMoveNoEmptyDirectories (5.51s) === RUN TestSyncEmptyDirectories run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-cehowil2kivu'", Local "Local file system at /tmp/rclone251320568", Modify Window "1ms" 2025/02/13 04:26:28 DEBUG : sub dir2: Making directory with metadata 2025/02/13 04:26:28 INFO : sub dir2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2025/02/13 04:26:28 INFO : sub dir: Set directory modification time (using DirSetModTime) 2025/02/13 04:26:29 DEBUG : sub dir: Making directory with metadata 2025/02/13 04:26:29 INFO : sub dir: Made directory with metadata (mtime=2001-02-03T04:05:06.499999999Z) 2025/02/13 04:26:29 DEBUG : sub dir2: Making directory with metadata 2025/02/13 04:26:30 INFO : sub dir2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2025/02/13 04:26:30 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2025/02/13 04:26:30 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-cehowil2kivu': Waiting for checks to finish 2025/02/13 04:26:30 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-cehowil2kivu': Waiting for transfers to finish 2025/02/13 04:26:32 DEBUG : sub dir/hello world: md5 = 9b30377261a223e16a4e7d2717ca1b9c OK 2025/02/13 04:26:32 INFO : sub dir/hello world: Copied (new) 2025/02/13 04:26:32 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-cehowil2kivu'", Local "Local file system at /tmp/rclone251320568", Modify Window "1ms" 2025/02/13 04:26:34 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestSyncEmptyDirectories (7.38s) === RUN TestSyncSetDelayedModTimes run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-cehowil2kivu'", Local "Local file system at /tmp/rclone251320568", Modify Window "1ms" sync_test.go:507: Backend doesn't have DirModTimeUpdatesOnWrite set --- SKIP: TestSyncSetDelayedModTimes (0.44s) === RUN TestSyncNoEmptyDirectories run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-cehowil2kivu'", Local "Local file system at /tmp/rclone251320568", Modify Window "1ms" 2025/02/13 04:26:36 INFO : sub dir2: Making directory 2025/02/13 04:26:36 DEBUG : Added delayed dir = "sub dir", newDst= 2025/02/13 04:26:36 DEBUG : Added delayed dir = "sub dir2", newDst= 2025/02/13 04:26:36 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2025/02/13 04:26:36 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-cehowil2kivu': Waiting for checks to finish 2025/02/13 04:26:36 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-cehowil2kivu': Waiting for transfers to finish 2025/02/13 04:26:38 DEBUG : sub dir/hello world: md5 = 9b333c2fd8c34fbc16c08ea4125eabe9 OK 2025/02/13 04:26:38 INFO : sub dir/hello world: Copied (new) 2025/02/13 04:26:38 DEBUG : Waiting for deletions to finish 2025/02/13 04:26:39 INFO : sub dir: Set directory modification time (using DirSetModTime) 2025/02/13 04:26:41 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestSyncNoEmptyDirectories (5.36s) === RUN TestServerSideCopy run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-cehowil2kivu'", Local "Local file system at /tmp/rclone251320568", Modify Window "1ms" 2025/02/13 04:26:44 DEBUG : sub dir/hello world: md5 = 90081542d446ea384cc09d65e35e4469 OK 2025/02/13 04:26:44 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-sigogek4cene" 2025/02/13 04:26:44 DEBUG : Creating backend with remote "TestDrive:crypt/om1snavonvmg9ddc6rs61udob4e7gvt5o6hrrh352fbaekvrc43g" sync_test.go:590: Server side copy (if possible) Encrypted drive 'TestCryptDrive:rclone-test-cehowil2kivu' -> Encrypted drive 'TestCryptDrive:rclone-test-sigogek4cene' 2025/02/13 04:26:45 DEBUG : Added delayed dir = "sub dir", newDst= 2025/02/13 04:26:46 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2025/02/13 04:26:46 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-sigogek4cene': Waiting for checks to finish 2025/02/13 04:26:46 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-sigogek4cene': Waiting for transfers to finish 2025/02/13 04:26:48 INFO : sub dir/hello world: Copied (server-side copy) 2025/02/13 04:26:49 INFO : sub dir: Set directory modification time (using DirSetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-cehowil2kivu'", Local "Local file system at /tmp/rclone251320568", Modify Window "1ms" 2025/02/13 04:26:49 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-sigogek4cene': Purge remote 2025/02/13 04:26:51 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestServerSideCopy (10.51s) === RUN TestCopyOverSelf run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-cehowil2kivu'", Local "Local file system at /tmp/rclone251320568", Modify Window "1ms" 2025/02/13 04:26:54 DEBUG : sub dir/hello world: md5 = 4b5578c372937f64aafd0a15d3eb12da OK 2025/02/13 04:26:55 INFO : sub dir: Set directory modification time (using SetModTime) 2025/02/13 04:26:55 DEBUG : Added delayed dir = "sub dir", newDst=sub dir 2025/02/13 04:26:56 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-cehowil2kivu': Waiting for checks to finish 2025/02/13 04:26:56 DEBUG : sub dir/hello world: Sizes differ (src 17 vs dst 11) 2025/02/13 04:26:56 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-cehowil2kivu': Waiting for transfers to finish 2025/02/13 04:26:57 DEBUG : sub dir/hello world: md5 = 848fdd16431c4e31ff4849f8dcd30708 OK 2025/02/13 04:26:57 INFO : sub dir/hello world: Copied (replaced existing) 2025/02/13 04:26:57 INFO : sub dir: Set directory modification time (using SetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-cehowil2kivu'", Local "Local file system at /tmp/rclone251320568", Modify Window "1ms" 2025/02/13 04:26:59 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestCopyOverSelf (8.46s) === RUN TestServerSideCopyOverSelf run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-cehowil2kivu'", Local "Local file system at /tmp/rclone251320568", Modify Window "1ms" 2025/02/13 04:27:03 DEBUG : sub dir/hello world: md5 = 2c85b0f36c5fdaaf0fb9f51f29b239a5 OK 2025/02/13 04:27:03 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-keyakat8yive" 2025/02/13 04:27:04 DEBUG : Creating backend with remote "TestDrive:crypt/re48lsfaqn33ffsd18j4fuv99r16v3enrl9ihjmfb05tjgl8932g" sync_test.go:626: Server side copy (if possible) Encrypted drive 'TestCryptDrive:rclone-test-cehowil2kivu' -> Encrypted drive 'TestCryptDrive:rclone-test-keyakat8yive' 2025/02/13 04:27:05 DEBUG : Added delayed dir = "sub dir", newDst= 2025/02/13 04:27:05 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2025/02/13 04:27:05 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-keyakat8yive': Waiting for checks to finish 2025/02/13 04:27:05 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-keyakat8yive': Waiting for transfers to finish 2025/02/13 04:27:08 INFO : sub dir/hello world: Copied (server-side copy) 2025/02/13 04:27:08 INFO : sub dir: Set directory modification time (using DirSetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-cehowil2kivu'", Local "Local file system at /tmp/rclone251320568", Modify Window "1ms" 2025/02/13 04:27:10 DEBUG : sub dir/hello world: md5 = 7d011cee5814d40d201840ff8fdb4eeb OK 2025/02/13 04:27:11 DEBUG : sub dir: Directory modification time the same (differ by 0s, within tolerance 1ms) 2025/02/13 04:27:11 DEBUG : Added delayed dir = "sub dir", newDst=sub dir 2025/02/13 04:27:11 DEBUG : sub dir/hello world: Sizes differ (src 17 vs dst 11) 2025/02/13 04:27:11 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-keyakat8yive': Waiting for checks to finish 2025/02/13 04:27:11 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-keyakat8yive': Waiting for transfers to finish 2025/02/13 04:27:13 INFO : sub dir/hello world: Copied (server-side copy) 2025/02/13 04:27:13 INFO : sub dir: Set directory modification time (using SetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-cehowil2kivu'", Local "Local file system at /tmp/rclone251320568", Modify Window "1ms" 2025/02/13 04:27:14 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-keyakat8yive': Purge remote 2025/02/13 04:27:15 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestServerSideCopyOverSelf (16.66s) === RUN TestMoveOverSelf run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-cehowil2kivu'", Local "Local file system at /tmp/rclone251320568", Modify Window "1ms" 2025/02/13 04:27:20 DEBUG : sub dir/hello world: md5 = 8cd78b49879ad6d5daa19deefc347b9c OK 2025/02/13 04:27:21 INFO : sub dir: Set directory modification time (using SetModTime) 2025/02/13 04:27:21 DEBUG : Added delayed dir = "sub dir", newDst=sub dir 2025/02/13 04:27:21 DEBUG : sub dir/hello world: Sizes differ (src 17 vs dst 11) 2025/02/13 04:27:21 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-cehowil2kivu': Waiting for checks to finish 2025/02/13 04:27:21 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-cehowil2kivu': Waiting for transfers to finish 2025/02/13 04:27:22 DEBUG : sub dir/hello world: md5 = bb5456f57bcd0d9b5f3b4acc7b6ae349 OK 2025/02/13 04:27:22 INFO : sub dir/hello world: Copied (replaced existing) 2025/02/13 04:27:22 INFO : sub dir/hello world: Deleted 2025/02/13 04:27:23 INFO : sub dir: Set directory modification time (using SetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-cehowil2kivu'", Local "Local file system at /tmp/rclone251320568", Modify Window "1ms" 2025/02/13 04:27:24 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestMoveOverSelf (8.65s) === RUN TestServerSideMoveOverSelf run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-cehowil2kivu'", Local "Local file system at /tmp/rclone251320568", Modify Window "1ms" 2025/02/13 04:27:28 DEBUG : sub dir/hello world: md5 = eba71f76f1c40f935e5d9e4e5689c6ab OK 2025/02/13 04:27:28 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-pagufaq8sihu" 2025/02/13 04:27:28 DEBUG : Creating backend with remote "TestDrive:crypt/gh4p8rbgfn67u437vnb6o0f0vtgprtdd5nedg4gaiuj6p3mfhp90" sync_test.go:671: Server side copy (if possible) Encrypted drive 'TestCryptDrive:rclone-test-cehowil2kivu' -> Encrypted drive 'TestCryptDrive:rclone-test-pagufaq8sihu' 2025/02/13 04:27:30 DEBUG : Added delayed dir = "sub dir", newDst= 2025/02/13 04:27:30 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2025/02/13 04:27:30 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pagufaq8sihu': Waiting for checks to finish 2025/02/13 04:27:30 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pagufaq8sihu': Waiting for transfers to finish 2025/02/13 04:27:32 INFO : sub dir/hello world: Copied (server-side copy) 2025/02/13 04:27:33 INFO : sub dir: Set directory modification time (using DirSetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-cehowil2kivu'", Local "Local file system at /tmp/rclone251320568", Modify Window "1ms" 2025/02/13 04:27:35 DEBUG : sub dir/hello world: md5 = b187e49300f9f8c485f38559fa2486eb OK 2025/02/13 04:27:36 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pagufaq8sihu': Using server-side directory move 2025/02/13 04:27:36 INFO : Encrypted drive 'TestCryptDrive:rclone-test-pagufaq8sihu': Server side directory move failed - fallback to file moves: can't copy directory - destination already exists 2025/02/13 04:27:36 DEBUG : sub dir: Directory modification time the same (differ by 0s, within tolerance 1ms) 2025/02/13 04:27:36 DEBUG : Added delayed dir = "sub dir", newDst=sub dir 2025/02/13 04:27:36 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pagufaq8sihu': Waiting for checks to finish 2025/02/13 04:27:36 DEBUG : sub dir/hello world: Sizes differ (src 17 vs dst 11) 2025/02/13 04:27:36 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pagufaq8sihu': Waiting for transfers to finish 2025/02/13 04:27:37 INFO : sub dir/hello world: Deleted 2025/02/13 04:27:37 INFO : sub dir/hello world: Moved (server-side) 2025/02/13 04:27:38 INFO : sub dir: Set directory modification time (using SetModTime) 2025/02/13 04:27:40 DEBUG : sub dir/hello world: md5 = 149ec3066b68cab08ae669c40eb64666 OK 2025/02/13 04:27:41 DEBUG : testing file moves 2025/02/13 04:27:41 DEBUG : sub dir: Directory modification time the same (differ by 0s, within tolerance 1ms) 2025/02/13 04:27:41 DEBUG : Added delayed dir = "sub dir", newDst=sub dir 2025/02/13 04:27:41 DEBUG : sub dir/hello world: Sizes differ (src 24 vs dst 17) 2025/02/13 04:27:41 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pagufaq8sihu': Waiting for checks to finish 2025/02/13 04:27:41 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pagufaq8sihu': Waiting for transfers to finish 2025/02/13 04:27:42 INFO : sub dir/hello world: Deleted 2025/02/13 04:27:42 INFO : sub dir/hello world: Moved (server-side) 2025/02/13 04:27:43 INFO : sub dir: Set directory modification time (using SetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-cehowil2kivu'", Local "Local file system at /tmp/rclone251320568", Modify Window "1ms" 2025/02/13 04:27:44 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pagufaq8sihu': Purge remote --- PASS: TestServerSideMoveOverSelf (21.14s) === RUN TestCopyAfterDelete run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-cehowil2kivu'", Local "Local file system at /tmp/rclone251320568", Modify Window "1ms" 2025/02/13 04:27:49 DEBUG : sub dir/hello world: md5 = d2e2e856a22608e21c21d7030f9821ba OK 2025/02/13 04:27:49 ERROR : : error listing: directory not found 2025/02/13 04:27:49 INFO : Local file system at /tmp/rclone251320568: Making directory 2025/02/13 04:27:50 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-cehowil2kivu': Waiting for checks to finish 2025/02/13 04:27:50 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-cehowil2kivu': Waiting for transfers to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-cehowil2kivu'", Local "Local file system at /tmp/rclone251320568", Modify Window "1ms" 2025/02/13 04:27:52 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestCopyAfterDelete (6.05s) === RUN TestCopyRedownload run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-cehowil2kivu'", Local "Local file system at /tmp/rclone251320568", Modify Window "1ms" 2025/02/13 04:27:55 DEBUG : sub dir/hello world: md5 = 73ad793395fbcb721fc31afa2c78895f OK 2025/02/13 04:27:56 DEBUG : Added delayed dir = "sub dir", newDst= 2025/02/13 04:27:56 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2025/02/13 04:27:56 DEBUG : Local file system at /tmp/rclone251320568: Waiting for checks to finish 2025/02/13 04:27:56 DEBUG : Local file system at /tmp/rclone251320568: Waiting for transfers to finish 2025/02/13 04:27:57 DEBUG : sub dir/hello world.285f0a30.partial: renamed to: sub dir/hello world 2025/02/13 04:27:57 INFO : sub dir/hello world: Copied (new) 2025/02/13 04:27:57 INFO : sub dir: Set directory modification time (using DirSetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-cehowil2kivu'", Local "Local file system at /tmp/rclone251320568", Modify Window "1ms" 2025/02/13 04:27:58 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestCopyRedownload (6.48s) === RUN TestSyncBasedOnCheckSum run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-cehowil2kivu'", Local "Local file system at /tmp/rclone251320568", Modify Window "1ms" 2025/02/13 04:28:00 DEBUG : check sum: Need to transfer - File not found at Destination 2025/02/13 04:28:00 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-cehowil2kivu': Waiting for checks to finish 2025/02/13 04:28:00 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-cehowil2kivu': Waiting for transfers to finish 2025/02/13 04:28:01 DEBUG : check sum: md5 = 55eb35ca0039cf6ebe745ceb4977ecb9 OK 2025/02/13 04:28:01 INFO : check sum: Copied (new) 2025/02/13 04:28:01 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-cehowil2kivu'", Local "Local file system at /tmp/rclone251320568", Modify Window "1ms" 2025/02/13 04:28:02 NOTICE: Encrypted drive 'TestCryptDrive:rclone-test-cehowil2kivu': --checksum is in use but the source and destination have no hashes in common; falling back to --size-only 2025/02/13 04:28:02 DEBUG : check sum: Size of src and dst objects identical 2025/02/13 04:28:02 DEBUG : check sum: Unchanged skipping 2025/02/13 04:28:02 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-cehowil2kivu': Waiting for checks to finish 2025/02/13 04:28:02 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-cehowil2kivu': Waiting for transfers to finish 2025/02/13 04:28:02 DEBUG : Waiting for deletions to finish 2025/02/13 04:28:02 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-cehowil2kivu'", Local "Local file system at /tmp/rclone251320568", Modify Window "1ms" --- PASS: TestSyncBasedOnCheckSum (4.69s) === RUN TestSyncSizeOnly run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-cehowil2kivu'", Local "Local file system at /tmp/rclone251320568", Modify Window "1ms" 2025/02/13 04:28:04 DEBUG : sizeonly: Need to transfer - File not found at Destination 2025/02/13 04:28:04 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-cehowil2kivu': Waiting for checks to finish 2025/02/13 04:28:04 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-cehowil2kivu': Waiting for transfers to finish 2025/02/13 04:28:06 DEBUG : sizeonly: md5 = 9526e0b86f346a175c5134f70e915f81 OK 2025/02/13 04:28:06 INFO : sizeonly: Copied (new) 2025/02/13 04:28:06 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-cehowil2kivu'", Local "Local file system at /tmp/rclone251320568", Modify Window "1ms" 2025/02/13 04:28:06 DEBUG : sizeonly: Sizes identical 2025/02/13 04:28:06 DEBUG : sizeonly: Unchanged skipping 2025/02/13 04:28:06 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-cehowil2kivu': Waiting for checks to finish 2025/02/13 04:28:06 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-cehowil2kivu': Waiting for transfers to finish 2025/02/13 04:28:06 DEBUG : Waiting for deletions to finish 2025/02/13 04:28:06 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-cehowil2kivu'", Local "Local file system at /tmp/rclone251320568", Modify Window "1ms" --- PASS: TestSyncSizeOnly (4.25s) === RUN TestSyncIgnoreSize run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-cehowil2kivu'", Local "Local file system at /tmp/rclone251320568", Modify Window "1ms" 2025/02/13 04:28:09 DEBUG : ignore-size: Need to transfer - File not found at Destination 2025/02/13 04:28:09 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-cehowil2kivu': Waiting for checks to finish 2025/02/13 04:28:09 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-cehowil2kivu': Waiting for transfers to finish 2025/02/13 04:28:10 DEBUG : ignore-size: md5 = 472bfb19e00a96a8d8dbc7c5752bed99 OK 2025/02/13 04:28:10 INFO : ignore-size: Copied (new) 2025/02/13 04:28:10 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-cehowil2kivu'", Local "Local file system at /tmp/rclone251320568", Modify Window "1ms" 2025/02/13 04:28:10 DEBUG : ignore-size: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/02/13 04:28:10 DEBUG : ignore-size: Unchanged skipping 2025/02/13 04:28:10 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-cehowil2kivu': Waiting for checks to finish 2025/02/13 04:28:10 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-cehowil2kivu': Waiting for transfers to finish 2025/02/13 04:28:10 DEBUG : Waiting for deletions to finish 2025/02/13 04:28:10 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-cehowil2kivu'", Local "Local file system at /tmp/rclone251320568", Modify Window "1ms" --- PASS: TestSyncIgnoreSize (4.30s) === RUN TestSyncIgnoreTimes run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-cehowil2kivu'", Local "Local file system at /tmp/rclone251320568", Modify Window "1ms" 2025/02/13 04:28:14 DEBUG : existing: md5 = b0815f270f883a9ec618fb2a55c72235 OK 2025/02/13 04:28:14 DEBUG : existing: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/02/13 04:28:14 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-cehowil2kivu': Waiting for checks to finish 2025/02/13 04:28:14 DEBUG : existing: Unchanged skipping 2025/02/13 04:28:14 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-cehowil2kivu': Waiting for transfers to finish 2025/02/13 04:28:14 DEBUG : Waiting for deletions to finish 2025/02/13 04:28:14 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-cehowil2kivu'", Local "Local file system at /tmp/rclone251320568", Modify Window "1ms" 2025/02/13 04:28:15 DEBUG : existing: Transferring unconditionally as --ignore-times is in use 2025/02/13 04:28:15 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-cehowil2kivu': Waiting for checks to finish 2025/02/13 04:28:15 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-cehowil2kivu': Waiting for transfers to finish 2025/02/13 04:28:16 DEBUG : existing: md5 = 62f36fbf68a371675350e553c8432b44 OK 2025/02/13 04:28:16 INFO : existing: Copied (replaced existing) 2025/02/13 04:28:16 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-cehowil2kivu'", Local "Local file system at /tmp/rclone251320568", Modify Window "1ms" --- PASS: TestSyncIgnoreTimes (5.45s) === RUN TestSyncIgnoreExisting run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-cehowil2kivu'", Local "Local file system at /tmp/rclone251320568", Modify Window "1ms" 2025/02/13 04:28:18 DEBUG : existing: Need to transfer - File not found at Destination 2025/02/13 04:28:18 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-cehowil2kivu': Waiting for checks to finish 2025/02/13 04:28:18 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-cehowil2kivu': Waiting for transfers to finish 2025/02/13 04:28:20 DEBUG : existing: md5 = 594dbcadfa55b78d85e17939eacb6b41 OK 2025/02/13 04:28:20 INFO : existing: Copied (new) 2025/02/13 04:28:20 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-cehowil2kivu'", Local "Local file system at /tmp/rclone251320568", Modify Window "1ms" 2025/02/13 04:28:20 DEBUG : existing: Destination exists, skipping 2025/02/13 04:28:20 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-cehowil2kivu': Waiting for checks to finish 2025/02/13 04:28:20 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-cehowil2kivu': Waiting for transfers to finish 2025/02/13 04:28:20 DEBUG : Waiting for deletions to finish 2025/02/13 04:28:20 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-cehowil2kivu'", Local "Local file system at /tmp/rclone251320568", Modify Window "1ms" --- PASS: TestSyncIgnoreExisting (4.16s) === RUN TestSyncIgnoreErrors run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-cehowil2kivu'", Local "Local file system at /tmp/rclone251320568", Modify Window "1ms" 2025/02/13 04:28:24 DEBUG : b/potato: md5 = 1bfa4ca8baff44894eb86e603a81e52d OK 2025/02/13 04:28:27 DEBUG : c/non empty space: md5 = e8450d37bf2d5c93293a6cef463ec645 OK 2025/02/13 04:28:27 INFO : d: Making directory 2025/02/13 04:28:28 DEBUG : Added delayed dir = "a", newDst= 2025/02/13 04:28:29 INFO : c: Set directory modification time (using SetModTime) 2025/02/13 04:28:29 DEBUG : Added delayed dir = "c", newDst=c 2025/02/13 04:28:29 DEBUG : a/potato2: Need to transfer - File not found at Destination 2025/02/13 04:28:29 DEBUG : c/non empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/02/13 04:28:29 DEBUG : c/non empty space: Unchanged skipping 2025/02/13 04:28:29 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-cehowil2kivu': Waiting for checks to finish 2025/02/13 04:28:29 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-cehowil2kivu': Waiting for transfers to finish 2025/02/13 04:28:31 DEBUG : a/potato2: md5 = b4524a22c9a2bebf928041c2394fb45f OK 2025/02/13 04:28:31 INFO : a/potato2: Copied (new) 2025/02/13 04:28:31 DEBUG : Waiting for deletions to finish 2025/02/13 04:28:32 INFO : b/potato: Deleted 2025/02/13 04:28:32 INFO : a: Set directory modification time (using DirSetModTime) 2025/02/13 04:28:32 INFO : d: Removing directory 2025/02/13 04:28:33 INFO : b: Removing directory 2025/02/13 04:28:33 DEBUG : 32d8ua6196mc1r7qkfog53rkg0: Rmdir: contains trashed file: "2m507n64kafsi59v9q71r281a4" 2025/02/13 04:28:33 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-cehowil2kivu': deleted 2 directories run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-cehowil2kivu'", Local "Local file system at /tmp/rclone251320568", Modify Window "1ms" 2025/02/13 04:28:36 DEBUG : 3i9du405pfogq3ncai6pg7ouio: Rmdir: contains trashed file: "982d3pss7t5pn0il16r2foj31s" 2025/02/13 04:28:36 DEBUG : 2bsvlrk2ne1lfitm6tttcu0qt8: Rmdir: contains trashed file: "89l8renevh3mji1c8r1p7qn6tg" --- PASS: TestSyncIgnoreErrors (15.40s) === RUN TestSyncAfterChangingModtimeOnly run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-cehowil2kivu'", Local "Local file system at /tmp/rclone251320568", Modify Window "1ms" 2025/02/13 04:28:39 DEBUG : empty space: md5 = a63d95e6a4e006824419c44bc3faeb4d OK 2025/02/13 04:28:39 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/02/13 04:28:39 NOTICE: empty space: Skipped copy as --dry-run is set (size 1) 2025/02/13 04:28:39 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-cehowil2kivu': Waiting for checks to finish 2025/02/13 04:28:39 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-cehowil2kivu': Waiting for transfers to finish 2025/02/13 04:28:39 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-cehowil2kivu'", Local "Local file system at /tmp/rclone251320568", Modify Window "1ms" 2025/02/13 04:28:40 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-cehowil2kivu': Waiting for checks to finish 2025/02/13 04:28:40 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/02/13 04:28:40 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-cehowil2kivu': Waiting for transfers to finish 2025/02/13 04:28:41 DEBUG : empty space: md5 = 31948c0d10b7eb4619747406a6d4a06b OK 2025/02/13 04:28:41 INFO : empty space: Copied (replaced existing) 2025/02/13 04:28:41 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-cehowil2kivu'", Local "Local file system at /tmp/rclone251320568", Modify Window "1ms" --- PASS: TestSyncAfterChangingModtimeOnly (5.55s) === RUN TestSyncAfterChangingModtimeOnlyWithNoUpdateModTime run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-cehowil2kivu'", Local "Local file system at /tmp/rclone251320568", Modify Window "1ms" sync_test.go:1016: Can't check this if no hashes supported --- PASS: TestSyncAfterChangingModtimeOnlyWithNoUpdateModTime (0.45s) === RUN TestSyncDoesntUpdateModtime run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-cehowil2kivu'", Local "Local file system at /tmp/rclone251320568", Modify Window "1ms" 2025/02/13 04:28:45 DEBUG : foo: md5 = 26e006d2db8bceea880691b35580574e OK 2025/02/13 04:28:45 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-cehowil2kivu': Waiting for checks to finish 2025/02/13 04:28:45 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/02/13 04:28:45 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-cehowil2kivu': Waiting for transfers to finish 2025/02/13 04:28:47 DEBUG : foo: md5 = d5c37b2fc32fceb8c5703518b9175e64 OK 2025/02/13 04:28:47 INFO : foo: Copied (replaced existing) 2025/02/13 04:28:47 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-cehowil2kivu'", Local "Local file system at /tmp/rclone251320568", Modify Window "1ms" --- PASS: TestSyncDoesntUpdateModtime (4.63s) === RUN TestSyncAfterAddingAFile run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-cehowil2kivu'", Local "Local file system at /tmp/rclone251320568", Modify Window "1ms" 2025/02/13 04:28:50 DEBUG : empty space: md5 = 8cfcebad54f4b7c38f3b169fad344af1 OK 2025/02/13 04:28:50 DEBUG : potato: Need to transfer - File not found at Destination 2025/02/13 04:28:50 DEBUG : empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/02/13 04:28:50 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-cehowil2kivu': Waiting for checks to finish 2025/02/13 04:28:50 DEBUG : empty space: Unchanged skipping 2025/02/13 04:28:50 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-cehowil2kivu': Waiting for transfers to finish 2025/02/13 04:28:52 DEBUG : potato: md5 = 447fa419b7c8472b3c4f171e4b9efaa7 OK 2025/02/13 04:28:52 INFO : potato: Copied (new) 2025/02/13 04:28:52 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-cehowil2kivu'", Local "Local file system at /tmp/rclone251320568", Modify Window "1ms" --- PASS: TestSyncAfterAddingAFile (5.57s) === RUN TestSyncAfterChangingFilesSizeOnly run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-cehowil2kivu'", Local "Local file system at /tmp/rclone251320568", Modify Window "1ms" 2025/02/13 04:28:55 DEBUG : potato: md5 = 850c38fb776b877361d9ba0e746d9302 OK 2025/02/13 04:28:56 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-cehowil2kivu': Waiting for checks to finish 2025/02/13 04:28:56 DEBUG : potato: Sizes differ (src 21 vs dst 60) 2025/02/13 04:28:56 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-cehowil2kivu': Waiting for transfers to finish 2025/02/13 04:28:57 DEBUG : potato: md5 = 1544214b8de9afbe5684973b462cf4df OK 2025/02/13 04:28:57 INFO : potato: Copied (replaced existing) 2025/02/13 04:28:57 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-cehowil2kivu'", Local "Local file system at /tmp/rclone251320568", Modify Window "1ms" --- PASS: TestSyncAfterChangingFilesSizeOnly (4.57s) === RUN TestSyncAfterChangingContentsOnly run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-cehowil2kivu'", Local "Local file system at /tmp/rclone251320568", Modify Window "1ms" 2025/02/13 04:29:00 DEBUG : potato: md5 = 40729941b1f9626a0942f814ef54976f OK 2025/02/13 04:29:00 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-cehowil2kivu': Waiting for checks to finish 2025/02/13 04:29:00 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/02/13 04:29:00 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-cehowil2kivu': Waiting for transfers to finish 2025/02/13 04:29:01 DEBUG : potato: md5 = 83f10276778642ac0c58fcef9300966b OK 2025/02/13 04:29:01 INFO : potato: Copied (replaced existing) 2025/02/13 04:29:01 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-cehowil2kivu'", Local "Local file system at /tmp/rclone251320568", Modify Window "1ms" --- PASS: TestSyncAfterChangingContentsOnly (4.59s) === RUN TestSyncAfterRemovingAFileAndAddingAFileDryRun run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-cehowil2kivu'", Local "Local file system at /tmp/rclone251320568", Modify Window "1ms" 2025/02/13 04:29:04 DEBUG : potato: md5 = 128a7ebca08d582a95a66de9c8ee2ed9 OK 2025/02/13 04:29:06 DEBUG : empty space: md5 = 9dca6931f9710e1baf31a46fac85005a OK 2025/02/13 04:29:06 DEBUG : potato2: Need to transfer - File not found at Destination 2025/02/13 04:29:06 NOTICE: potato2: Skipped copy as --dry-run is set (size 60) 2025/02/13 04:29:06 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-cehowil2kivu': Waiting for checks to finish 2025/02/13 04:29:06 DEBUG : empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/02/13 04:29:06 DEBUG : empty space: Unchanged skipping 2025/02/13 04:29:06 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-cehowil2kivu': Waiting for transfers to finish 2025/02/13 04:29:06 DEBUG : Waiting for deletions to finish 2025/02/13 04:29:06 NOTICE: potato: Skipped delete as --dry-run is set (size 21) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-cehowil2kivu'", Local "Local file system at /tmp/rclone251320568", Modify Window "1ms" --- PASS: TestSyncAfterRemovingAFileAndAddingAFileDryRun (5.17s) === RUN TestSyncAfterRemovingAFileAndAddingAFile run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-cehowil2kivu'", Local "Local file system at /tmp/rclone251320568", Modify Window "1ms" 2025/02/13 04:29:10 DEBUG : potato: md5 = c87c1269ebb41ed3fdbdd3d04ce4890e OK 2025/02/13 04:29:11 DEBUG : empty space: md5 = c7ace71773b1884f23c5afcbf7e2d051 OK 2025/02/13 04:29:11 DEBUG : potato2: Need to transfer - File not found at Destination 2025/02/13 04:29:11 DEBUG : empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/02/13 04:29:11 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-cehowil2kivu': Waiting for checks to finish 2025/02/13 04:29:11 DEBUG : empty space: Unchanged skipping 2025/02/13 04:29:11 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-cehowil2kivu': Waiting for transfers to finish 2025/02/13 04:29:13 DEBUG : potato2: md5 = f28911f5a2770e61d104891d2ba9c809 OK 2025/02/13 04:29:13 INFO : potato2: Copied (new) 2025/02/13 04:29:13 DEBUG : Waiting for deletions to finish 2025/02/13 04:29:13 INFO : potato: Deleted run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-cehowil2kivu'", Local "Local file system at /tmp/rclone251320568", Modify Window "1ms" --- PASS: TestSyncAfterRemovingAFileAndAddingAFile (7.47s) === RUN TestSyncAfterRemovingAFileAndAddingAFileSubDir run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-cehowil2kivu'", Local "Local file system at /tmp/rclone251320568", Modify Window "1ms" 2025/02/13 04:29:18 DEBUG : b/potato: md5 = 380d1cef913cd3ee6dd5325cef48aa3e OK 2025/02/13 04:29:20 DEBUG : c/non empty space: md5 = 6944bf72a59bb78a132abad6e3e68937 OK 2025/02/13 04:29:20 INFO : d: Making directory 2025/02/13 04:29:21 INFO : d/e: Making directory 2025/02/13 04:29:22 DEBUG : Added delayed dir = "a", newDst= 2025/02/13 04:29:23 INFO : c: Set directory modification time (using SetModTime) 2025/02/13 04:29:23 DEBUG : Added delayed dir = "c", newDst=c 2025/02/13 04:29:23 DEBUG : a/potato2: Need to transfer - File not found at Destination 2025/02/13 04:29:23 DEBUG : c/non empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/02/13 04:29:23 DEBUG : c/non empty space: Unchanged skipping 2025/02/13 04:29:25 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-cehowil2kivu': Waiting for checks to finish 2025/02/13 04:29:25 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-cehowil2kivu': Waiting for transfers to finish 2025/02/13 04:29:25 DEBUG : a/potato2: md5 = 79a378f96604fa26334b4cde6d10d1a4 OK 2025/02/13 04:29:25 INFO : a/potato2: Copied (new) 2025/02/13 04:29:25 DEBUG : Waiting for deletions to finish 2025/02/13 04:29:25 INFO : b/potato: Deleted 2025/02/13 04:29:26 INFO : a: Set directory modification time (using DirSetModTime) 2025/02/13 04:29:26 INFO : d/e: Removing directory 2025/02/13 04:29:27 INFO : d: Removing directory 2025/02/13 04:29:27 DEBUG : ka6id8d20d3s5ktapedlphgta8: Rmdir: contains trashed file: "r8sppajuabeak3sbgj2ak8vuf8" 2025/02/13 04:29:27 INFO : b: Removing directory 2025/02/13 04:29:28 DEBUG : 32d8ua6196mc1r7qkfog53rkg0: Rmdir: contains trashed file: "2m507n64kafsi59v9q71r281a4" 2025/02/13 04:29:28 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-cehowil2kivu': deleted 3 directories run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-cehowil2kivu'", Local "Local file system at /tmp/rclone251320568", Modify Window "1ms" 2025/02/13 04:29:31 DEBUG : 3i9du405pfogq3ncai6pg7ouio: Rmdir: contains trashed file: "982d3pss7t5pn0il16r2foj31s" 2025/02/13 04:29:31 DEBUG : 2bsvlrk2ne1lfitm6tttcu0qt8: Rmdir: contains trashed file: "89l8renevh3mji1c8r1p7qn6tg" --- PASS: TestSyncAfterRemovingAFileAndAddingAFileSubDir (16.76s) === RUN TestSyncAfterRemovingAFileAndAddingAFileSubDirWithErrors run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-cehowil2kivu'", Local "Local file system at /tmp/rclone251320568", Modify Window "1ms" 2025/02/13 04:29:34 DEBUG : b/potato: md5 = a2e3be275cfb98d43a1554b9c62b846b OK 2025/02/13 04:29:37 DEBUG : c/non empty space: md5 = 9f202fba13a37603c8ec1f4aa67cf7b3 OK 2025/02/13 04:29:37 INFO : d: Making directory 2025/02/13 04:29:38 DEBUG : Added delayed dir = "a", newDst= 2025/02/13 04:29:38 INFO : c: Set directory modification time (using SetModTime) 2025/02/13 04:29:38 DEBUG : Added delayed dir = "c", newDst=c 2025/02/13 04:29:38 DEBUG : a/potato2: Need to transfer - File not found at Destination 2025/02/13 04:29:39 DEBUG : c/non empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/02/13 04:29:39 DEBUG : c/non empty space: Unchanged skipping 2025/02/13 04:29:39 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-cehowil2kivu': Waiting for checks to finish 2025/02/13 04:29:39 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-cehowil2kivu': Waiting for transfers to finish 2025/02/13 04:29:41 DEBUG : a/potato2: md5 = b0fcd404c40f8e32a4671800ca33e215 OK 2025/02/13 04:29:41 INFO : a/potato2: Copied (new) 2025/02/13 04:29:41 ERROR : Encrypted drive 'TestCryptDrive:rclone-test-cehowil2kivu': not deleting files as there were IO errors 2025/02/13 04:29:41 INFO : a: Set directory modification time (using DirSetModTime) 2025/02/13 04:29:41 ERROR : Encrypted drive 'TestCryptDrive:rclone-test-cehowil2kivu': not deleting directories as there were IO errors run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-cehowil2kivu'", Local "Local file system at /tmp/rclone251320568", Modify Window "1ms" 2025/02/13 04:29:45 DEBUG : 3i9du405pfogq3ncai6pg7ouio: Rmdir: contains trashed file: "982d3pss7t5pn0il16r2foj31s" 2025/02/13 04:29:46 DEBUG : 32d8ua6196mc1r7qkfog53rkg0: Rmdir: contains trashed file: "2m507n64kafsi59v9q71r281a4" 2025/02/13 04:29:46 DEBUG : 2bsvlrk2ne1lfitm6tttcu0qt8: Rmdir: contains trashed file: "89l8renevh3mji1c8r1p7qn6tg" --- PASS: TestSyncAfterRemovingAFileAndAddingAFileSubDirWithErrors (15.23s) === RUN TestSyncDeleteAfter --- PASS: TestSyncDeleteAfter (0.00s) === RUN TestSyncDeleteDuring run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-cehowil2kivu'", Local "Local file system at /tmp/rclone251320568", Modify Window "1ms" 2025/02/13 04:29:49 DEBUG : potato: md5 = 7fc3eca8edf029650bf038d8d362c932 OK 2025/02/13 04:29:50 DEBUG : empty space: md5 = 2beaa32fae8f693e99bba1f7f93c8465 OK 2025/02/13 04:29:51 DEBUG : Waiting for deletions to finish 2025/02/13 04:29:51 DEBUG : potato2: Need to transfer - File not found at Destination 2025/02/13 04:29:51 DEBUG : empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/02/13 04:29:51 DEBUG : empty space: Unchanged skipping 2025/02/13 04:29:51 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-cehowil2kivu': Waiting for checks to finish 2025/02/13 04:29:51 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-cehowil2kivu': Waiting for transfers to finish 2025/02/13 04:29:51 INFO : potato: Deleted 2025/02/13 04:29:52 DEBUG : potato2: md5 = 3b0df5b52d4b4758c7506d997062f2be OK 2025/02/13 04:29:52 INFO : potato2: Copied (new) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-cehowil2kivu'", Local "Local file system at /tmp/rclone251320568", Modify Window "1ms" --- PASS: TestSyncDeleteDuring (6.79s) === RUN TestSyncDeleteBefore run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-cehowil2kivu'", Local "Local file system at /tmp/rclone251320568", Modify Window "1ms" 2025/02/13 04:29:56 DEBUG : potato: md5 = 4036a7fc72a6444ce7d38bf6e42ac671 OK 2025/02/13 04:29:57 DEBUG : empty space: md5 = dd0503643f62fd448efa35d7982a9655 OK 2025/02/13 04:29:58 DEBUG : Waiting for deletions to finish 2025/02/13 04:29:58 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-cehowil2kivu': Waiting for checks to finish 2025/02/13 04:29:58 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-cehowil2kivu': Waiting for transfers to finish 2025/02/13 04:29:58 INFO : potato: Deleted 2025/02/13 04:29:58 DEBUG : potato2: Need to transfer - File not found at Destination 2025/02/13 04:29:58 DEBUG : empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/02/13 04:29:58 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-cehowil2kivu': Waiting for checks to finish 2025/02/13 04:29:58 DEBUG : empty space: Unchanged skipping 2025/02/13 04:29:58 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-cehowil2kivu': Waiting for transfers to finish 2025/02/13 04:30:00 DEBUG : potato2: md5 = b1474c7f8ad52e6759d573f960f02f68 OK 2025/02/13 04:30:00 INFO : potato2: Copied (new) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-cehowil2kivu'", Local "Local file system at /tmp/rclone251320568", Modify Window "1ms" --- PASS: TestSyncDeleteBefore (7.64s) === RUN TestCopyDeleteBefore run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-cehowil2kivu'", Local "Local file system at /tmp/rclone251320568", Modify Window "1ms" 2025/02/13 04:30:03 DEBUG : potato: md5 = f7f8ea1675351831aac8309cb585abd3 OK 2025/02/13 04:30:04 DEBUG : potato2: Need to transfer - File not found at Destination 2025/02/13 04:30:04 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-cehowil2kivu': Waiting for checks to finish 2025/02/13 04:30:04 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-cehowil2kivu': Waiting for transfers to finish 2025/02/13 04:30:05 DEBUG : potato2: md5 = a2ce8f9aed780ec5d946898085e91671 OK 2025/02/13 04:30:05 INFO : potato2: Copied (new) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-cehowil2kivu'", Local "Local file system at /tmp/rclone251320568", Modify Window "1ms" --- PASS: TestCopyDeleteBefore (5.37s) === RUN TestSyncWithExclude run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-cehowil2kivu'", Local "Local file system at /tmp/rclone251320568", Modify Window "1ms" 2025/02/13 04:30:09 DEBUG : potato2: md5 = d21dd964a4891bb0dba96d64293608f5 OK 2025/02/13 04:30:10 DEBUG : empty space: md5 = c12d153a61dc4c54ff4b4aa80213c27d OK 2025/02/13 04:30:11 DEBUG : enormous: Excluded (Size Filter) 2025/02/13 04:30:11 DEBUG : enormous: Excluded 2025/02/13 04:30:11 DEBUG : potato2: Excluded (Size Filter) 2025/02/13 04:30:11 DEBUG : potato2: Excluded 2025/02/13 04:30:11 DEBUG : potato2: Excluded (Size Filter) 2025/02/13 04:30:11 DEBUG : potato2: Excluded 2025/02/13 04:30:11 DEBUG : empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/02/13 04:30:11 DEBUG : empty space: Unchanged skipping 2025/02/13 04:30:11 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-cehowil2kivu': Waiting for checks to finish 2025/02/13 04:30:11 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-cehowil2kivu': Waiting for transfers to finish 2025/02/13 04:30:11 DEBUG : Waiting for deletions to finish 2025/02/13 04:30:11 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-cehowil2kivu'", Local "Local file system at /tmp/rclone251320568", Modify Window "1ms" 2025/02/13 04:30:11 DEBUG : enormous: Excluded (Size Filter) 2025/02/13 04:30:11 DEBUG : enormous: Excluded 2025/02/13 04:30:11 DEBUG : potato2: Excluded (Size Filter) 2025/02/13 04:30:11 DEBUG : potato2: Excluded 2025/02/13 04:30:11 DEBUG : potato2: Excluded (Size Filter) 2025/02/13 04:30:11 DEBUG : potato2: Excluded 2025/02/13 04:30:11 DEBUG : empty space: Size and modification time the same (differ by 456.789µs, within tolerance 1ms) 2025/02/13 04:30:11 DEBUG : empty space: Unchanged skipping 2025/02/13 04:30:11 DEBUG : Local file system at /tmp/rclone251320568: Waiting for checks to finish 2025/02/13 04:30:11 DEBUG : Local file system at /tmp/rclone251320568: Waiting for transfers to finish 2025/02/13 04:30:11 DEBUG : Waiting for deletions to finish 2025/02/13 04:30:11 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-cehowil2kivu'", Local "Local file system at /tmp/rclone251320568", Modify Window "1ms" --- PASS: TestSyncWithExclude (6.24s) === RUN TestSyncWithExcludeAndDeleteExcluded run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-cehowil2kivu'", Local "Local file system at /tmp/rclone251320568", Modify Window "1ms" 2025/02/13 04:30:15 DEBUG : potato2: md5 = f89b1c1fa3bcc18912154d2ff726fba5 OK 2025/02/13 04:30:17 DEBUG : empty space: md5 = b71d5f24a75874de63443a49950ebfe7 OK 2025/02/13 04:30:18 DEBUG : enormous: md5 = 4446bb8ccca2e377206763973a772223 OK 2025/02/13 04:30:18 DEBUG : enormous: Excluded (Size Filter) 2025/02/13 04:30:18 DEBUG : enormous: Excluded 2025/02/13 04:30:18 DEBUG : potato2: Excluded (Size Filter) 2025/02/13 04:30:18 DEBUG : potato2: Excluded 2025/02/13 04:30:18 DEBUG : empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/02/13 04:30:18 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-cehowil2kivu': Waiting for checks to finish 2025/02/13 04:30:18 DEBUG : empty space: Unchanged skipping 2025/02/13 04:30:18 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-cehowil2kivu': Waiting for transfers to finish 2025/02/13 04:30:18 DEBUG : Waiting for deletions to finish 2025/02/13 04:30:19 INFO : potato2: Deleted 2025/02/13 04:30:19 INFO : enormous: Deleted 2025/02/13 04:30:19 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-cehowil2kivu'", Local "Local file system at /tmp/rclone251320568", Modify Window "1ms" 2025/02/13 04:30:19 DEBUG : Local file system at /tmp/rclone251320568: Waiting for checks to finish 2025/02/13 04:30:19 DEBUG : empty space: Size and modification time the same (differ by 456.789µs, within tolerance 1ms) 2025/02/13 04:30:19 DEBUG : empty space: Unchanged skipping 2025/02/13 04:30:19 DEBUG : Local file system at /tmp/rclone251320568: Waiting for transfers to finish 2025/02/13 04:30:19 DEBUG : Waiting for deletions to finish 2025/02/13 04:30:19 INFO : potato2: Deleted 2025/02/13 04:30:19 INFO : enormous: Deleted 2025/02/13 04:30:19 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-cehowil2kivu'", Local "Local file system at /tmp/rclone251320568", Modify Window "1ms" --- PASS: TestSyncWithExcludeAndDeleteExcluded (7.65s) === RUN TestSyncWithUpdateOlder run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-cehowil2kivu'", Local "Local file system at /tmp/rclone251320568", Modify Window "1ms" 2025/02/13 04:30:23 DEBUG : one: md5 = aafea749d64a977364ef3af96e12baa1 OK 2025/02/13 04:30:24 DEBUG : two: md5 = 89e2b1daebb6d86d2222be9913cf39f4 OK 2025/02/13 04:30:25 DEBUG : three: md5 = 6117ccee1b88732bfb99a8e9f4e830ed OK 2025/02/13 04:30:27 DEBUG : four: md5 = 0058ea9fc53a9c564dfa34c721a10f57 OK 2025/02/13 04:30:27 DEBUG : five: Need to transfer - File not found at Destination 2025/02/13 04:30:27 DEBUG : one: Destination is newer than source, skipping 2025/02/13 04:30:27 DEBUG : four: Sizes differ (src 4 vs dst 8) 2025/02/13 04:30:27 DEBUG : three: Sizes identical 2025/02/13 04:30:27 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-cehowil2kivu': Waiting for checks to finish 2025/02/13 04:30:27 DEBUG : four: Destination mod time is within 1s of source but files differ, transferring 2025/02/13 04:30:27 DEBUG : three: Destination mod time is within 1s of source and files identical, skipping 2025/02/13 04:30:27 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-cehowil2kivu': Waiting for transfers to finish 2025/02/13 04:30:29 DEBUG : two: md5 = 1b13beb265c129632bd25d06add45956 OK 2025/02/13 04:30:29 INFO : two: Copied (replaced existing) 2025/02/13 04:30:29 DEBUG : four: md5 = 7a6c2810a19f12fad4d502ad4bc8f5ad OK 2025/02/13 04:30:29 INFO : four: Copied (replaced existing) 2025/02/13 04:30:29 DEBUG : five: md5 = d52dd9fbb6e249c6538c0c8d8a3a314a OK 2025/02/13 04:30:29 INFO : five: Copied (new) 2025/02/13 04:30:29 DEBUG : Waiting for deletions to finish sync_test.go:1449: Skip test with --checksum as no hashes supported --- PASS: TestSyncWithUpdateOlder (10.58s) === 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-cehowil2kivu'", Local "Local file system at /tmp/rclone251320568", Modify Window "1ms" sync_test.go:1538: Can track renames: false 2025/02/13 04:30:32 ERROR : Encrypted drive 'TestCryptDrive:rclone-test-cehowil2kivu': Ignoring --track-renames as the source and destination do not have a common hash 2025/02/13 04:30:32 DEBUG : potato: Need to transfer - File not found at Destination 2025/02/13 04:30:32 DEBUG : yam: Need to transfer - File not found at Destination 2025/02/13 04:30:32 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-cehowil2kivu': Waiting for checks to finish 2025/02/13 04:30:32 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-cehowil2kivu': Waiting for transfers to finish 2025/02/13 04:30:34 DEBUG : yam: md5 = 28254c8b61c8d95773b2cc3b075aa04e OK 2025/02/13 04:30:34 INFO : yam: Copied (new) 2025/02/13 04:30:34 DEBUG : potato: md5 = 4c7245e3d851077980006bd455a43eea OK 2025/02/13 04:30:34 INFO : potato: Copied (new) 2025/02/13 04:30:34 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-cehowil2kivu'", Local "Local file system at /tmp/rclone251320568", Modify Window "1ms" 2025/02/13 04:30:34 ERROR : Encrypted drive 'TestCryptDrive:rclone-test-cehowil2kivu': Ignoring --track-renames as the source and destination do not have a common hash 2025/02/13 04:30:34 DEBUG : yaml: Need to transfer - File not found at Destination 2025/02/13 04:30:34 DEBUG : potato: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/02/13 04:30:34 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-cehowil2kivu': Waiting for checks to finish 2025/02/13 04:30:34 DEBUG : potato: Unchanged skipping 2025/02/13 04:30:34 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-cehowil2kivu': Waiting for transfers to finish 2025/02/13 04:30:36 DEBUG : yaml: md5 = d1b10e6af05f0297b60742b25d060bd3 OK 2025/02/13 04:30:36 INFO : yaml: Copied (new) 2025/02/13 04:30:36 DEBUG : Waiting for deletions to finish 2025/02/13 04:30:36 INFO : yam: Deleted run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-cehowil2kivu'", Local "Local file system at /tmp/rclone251320568", Modify Window "1ms" --- PASS: TestSyncWithTrackRenames (7.09s) === RUN TestParseRenamesStrategyModtime --- PASS: TestParseRenamesStrategyModtime (0.00s) === RUN TestRenamesStrategyModtime --- PASS: TestRenamesStrategyModtime (0.00s) === RUN TestSyncWithTrackRenamesStrategyModtime run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-cehowil2kivu'", Local "Local file system at /tmp/rclone251320568", Modify Window "1ms" sync_test.go:1610: Can track renames: true 2025/02/13 04:30:39 INFO : Encrypted drive 'TestCryptDrive:rclone-test-cehowil2kivu': Making map for --track-renames 2025/02/13 04:30:39 INFO : Encrypted drive 'TestCryptDrive:rclone-test-cehowil2kivu': Finished making map for --track-renames 2025/02/13 04:30:39 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-cehowil2kivu': Waiting for checks to finish 2025/02/13 04:30:39 DEBUG : potato: Need to transfer - No matching file found at Destination 2025/02/13 04:30:39 DEBUG : yam: Need to transfer - No matching file found at Destination 2025/02/13 04:30:39 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-cehowil2kivu': Waiting for renames to finish 2025/02/13 04:30:39 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-cehowil2kivu': Waiting for transfers to finish 2025/02/13 04:30:41 DEBUG : potato: md5 = dd69cf186bbbe87302416329aa583adf OK 2025/02/13 04:30:41 INFO : potato: Copied (new) 2025/02/13 04:30:41 DEBUG : yam: md5 = fb1031cc0ffd118e90cb74f85469b49a OK 2025/02/13 04:30:41 INFO : yam: Copied (new) 2025/02/13 04:30:41 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-cehowil2kivu'", Local "Local file system at /tmp/rclone251320568", Modify Window "1ms" 2025/02/13 04:30:41 DEBUG : potato: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/02/13 04:30:41 INFO : Encrypted drive 'TestCryptDrive:rclone-test-cehowil2kivu': Making map for --track-renames 2025/02/13 04:30:41 INFO : Encrypted drive 'TestCryptDrive:rclone-test-cehowil2kivu': Finished making map for --track-renames 2025/02/13 04:30:41 DEBUG : potato: Unchanged skipping 2025/02/13 04:30:41 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-cehowil2kivu': Waiting for checks to finish 2025/02/13 04:30:41 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-cehowil2kivu': Waiting for renames to finish 2025/02/13 04:30:42 INFO : yam: Moved (server-side) to: yaml 2025/02/13 04:30:42 INFO : yaml: Renamed from "yam" 2025/02/13 04:30:42 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-cehowil2kivu': Waiting for transfers to finish 2025/02/13 04:30:42 DEBUG : Waiting for deletions to finish 2025/02/13 04:30:42 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-cehowil2kivu'", Local "Local file system at /tmp/rclone251320568", Modify Window "1ms" --- PASS: TestSyncWithTrackRenamesStrategyModtime (5.64s) === RUN TestSyncWithTrackRenamesStrategyLeaf run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-cehowil2kivu'", Local "Local file system at /tmp/rclone251320568", Modify Window "1ms" sync_test.go:1649: Can track renames: true 2025/02/13 04:30:45 DEBUG : Added delayed dir = "sub", newDst= 2025/02/13 04:30:45 INFO : Encrypted drive 'TestCryptDrive:rclone-test-cehowil2kivu': Making map for --track-renames 2025/02/13 04:30:45 INFO : Encrypted drive 'TestCryptDrive:rclone-test-cehowil2kivu': Finished making map for --track-renames 2025/02/13 04:30:45 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-cehowil2kivu': Waiting for checks to finish 2025/02/13 04:30:45 DEBUG : potato: Need to transfer - No matching file found at Destination 2025/02/13 04:30:45 DEBUG : sub/yam: Need to transfer - No matching file found at Destination 2025/02/13 04:30:45 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-cehowil2kivu': Waiting for renames to finish 2025/02/13 04:30:45 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-cehowil2kivu': Waiting for transfers to finish 2025/02/13 04:30:47 DEBUG : potato: md5 = dcc15a1d4eb512f00e07c1c0a429b461 OK 2025/02/13 04:30:47 INFO : potato: Copied (new) 2025/02/13 04:30:47 DEBUG : sub/yam: md5 = 4ed800822d409c80c60863a458ec6637 OK 2025/02/13 04:30:47 INFO : sub/yam: Copied (new) 2025/02/13 04:30:47 DEBUG : Waiting for deletions to finish 2025/02/13 04:30:48 INFO : sub: Set directory modification time (using DirSetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-cehowil2kivu'", Local "Local file system at /tmp/rclone251320568", Modify Window "1ms" 2025/02/13 04:30:48 DEBUG : potato: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/02/13 04:30:48 DEBUG : potato: Unchanged skipping 2025/02/13 04:30:49 INFO : sub: Set directory modification time (using SetModTime) 2025/02/13 04:30:49 DEBUG : Added delayed dir = "sub", newDst=sub 2025/02/13 04:30:49 INFO : Encrypted drive 'TestCryptDrive:rclone-test-cehowil2kivu': Making map for --track-renames 2025/02/13 04:30:49 INFO : Encrypted drive 'TestCryptDrive:rclone-test-cehowil2kivu': Finished making map for --track-renames 2025/02/13 04:30:49 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-cehowil2kivu': Waiting for checks to finish 2025/02/13 04:30:49 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-cehowil2kivu': Waiting for renames to finish 2025/02/13 04:30:50 INFO : sub/yam: Moved (server-side) to: yam 2025/02/13 04:30:50 INFO : yam: Renamed from "sub/yam" 2025/02/13 04:30:50 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-cehowil2kivu': Waiting for transfers to finish 2025/02/13 04:30:50 DEBUG : Waiting for deletions to finish 2025/02/13 04:30:50 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-cehowil2kivu'", Local "Local file system at /tmp/rclone251320568", Modify Window "1ms" --- PASS: TestSyncWithTrackRenamesStrategyLeaf (8.87s) === RUN TestServerSideMoveLocal run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-cehowil2kivu'", Local "Local file system at /tmp/rclone251320568", Modify Window "1ms" 2025/02/13 04:30:54 DEBUG : Creating backend with remote "/tmp/rclone251320568/dir1" 2025/02/13 04:30:54 DEBUG : Creating backend with remote "/tmp/rclone251320568/dir2" 2025/02/13 04:30:54 DEBUG : Local file system at /tmp/rclone251320568/dir2: Using server-side directory move 2025/02/13 04:30:54 INFO : Local file system at /tmp/rclone251320568/dir2: Server side directory move failed - fallback to file moves: can't copy directory - destination already exists 2025/02/13 04:30:54 DEBUG : file1.txt: Need to transfer - File not found at Destination 2025/02/13 04:30:54 DEBUG : Local file system at /tmp/rclone251320568/dir2: Waiting for checks to finish 2025/02/13 04:30:54 DEBUG : Local file system at /tmp/rclone251320568/dir2: Waiting for transfers to finish 2025/02/13 04:30:54 INFO : file1.txt: Moved (server-side) --- PASS: TestServerSideMoveLocal (0.46s) === RUN TestMoveWithDeleteEmptySrcDirs run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-cehowil2kivu'", Local "Local file system at /tmp/rclone251320568", Modify Window "1ms" 2025/02/13 04:30:54 DEBUG : Added delayed dir = "nested", newDst= 2025/02/13 04:30:54 DEBUG : Added delayed dir = "sub dir", newDst= 2025/02/13 04:30:54 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2025/02/13 04:30:54 DEBUG : Added delayed dir = "nested/sub dir", newDst= 2025/02/13 04:30:54 DEBUG : nested/sub dir/file: Need to transfer - File not found at Destination 2025/02/13 04:30:54 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-cehowil2kivu': Waiting for checks to finish 2025/02/13 04:30:54 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-cehowil2kivu': Waiting for transfers to finish 2025/02/13 04:30:57 DEBUG : sub dir/hello world: md5 = be49903a2a6b128152d0b2b0ee5afbca OK 2025/02/13 04:30:57 INFO : sub dir/hello world: Copied (new) 2025/02/13 04:30:57 INFO : sub dir/hello world: Deleted 2025/02/13 04:30:58 DEBUG : nested/sub dir/file: md5 = dc4e8dad55ca61c08c2c3c33b51473d4 OK 2025/02/13 04:30:58 INFO : nested/sub dir/file: Copied (new) 2025/02/13 04:30:58 INFO : nested/sub dir/file: Deleted 2025/02/13 04:30:59 INFO : nested/sub dir: Set directory modification time (using DirSetModTime) 2025/02/13 04:30:59 INFO : nested: Set directory modification time (using DirSetModTime) 2025/02/13 04:30:59 INFO : sub dir: Set directory modification time (using DirSetModTime) 2025/02/13 04:30:59 INFO : sub dir: Removing directory 2025/02/13 04:30:59 INFO : nested/sub dir: Removing directory 2025/02/13 04:30:59 INFO : nested: Removing directory 2025/02/13 04:30:59 DEBUG : Local file system at /tmp/rclone251320568: deleted 3 directories run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-cehowil2kivu'", Local "Local file system at /tmp/rclone251320568", Modify Window "1ms" 2025/02/13 04:31:02 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" 2025/02/13 04:31:03 DEBUG : 37qp6d1gohacv723ij3brofbu8/14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "ftp4kuv8se7tqduu6pmmcvjsmk" 2025/02/13 04:31:03 DEBUG : 37qp6d1gohacv723ij3brofbu8: Rmdir: contains trashed file: "14begaa36ih249fgrnfk6nulg0" --- PASS: TestMoveWithDeleteEmptySrcDirs (10.52s) === RUN TestMoveWithoutDeleteEmptySrcDirs run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-cehowil2kivu'", Local "Local file system at /tmp/rclone251320568", Modify Window "1ms" 2025/02/13 04:31:05 DEBUG : Added delayed dir = "nested", newDst= 2025/02/13 04:31:05 DEBUG : Added delayed dir = "sub dir", newDst= 2025/02/13 04:31:05 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2025/02/13 04:31:05 DEBUG : Added delayed dir = "nested/sub dir", newDst= 2025/02/13 04:31:05 DEBUG : nested/sub dir/file: Need to transfer - File not found at Destination 2025/02/13 04:31:05 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-cehowil2kivu': Waiting for checks to finish 2025/02/13 04:31:05 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-cehowil2kivu': Waiting for transfers to finish 2025/02/13 04:31:07 DEBUG : sub dir/hello world: md5 = f0ef6f3f236ab9f5b0d3687011e7a523 OK 2025/02/13 04:31:07 INFO : sub dir/hello world: Copied (new) 2025/02/13 04:31:07 INFO : sub dir/hello world: Deleted 2025/02/13 04:31:08 DEBUG : nested/sub dir/file: md5 = 584fcdb57e4e1d014565685568354cab OK 2025/02/13 04:31:08 INFO : nested/sub dir/file: Copied (new) 2025/02/13 04:31:08 INFO : nested/sub dir/file: Deleted 2025/02/13 04:31:09 INFO : nested/sub dir: Set directory modification time (using DirSetModTime) 2025/02/13 04:31:09 INFO : sub dir: Set directory modification time (using DirSetModTime) 2025/02/13 04:31:09 INFO : nested: Set directory modification time (using DirSetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-cehowil2kivu'", Local "Local file system at /tmp/rclone251320568", Modify Window "1ms" 2025/02/13 04:31:12 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" 2025/02/13 04:31:13 DEBUG : 37qp6d1gohacv723ij3brofbu8/14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "ftp4kuv8se7tqduu6pmmcvjsmk" 2025/02/13 04:31:14 DEBUG : 37qp6d1gohacv723ij3brofbu8: Rmdir: contains trashed file: "14begaa36ih249fgrnfk6nulg0" --- PASS: TestMoveWithoutDeleteEmptySrcDirs (10.43s) === RUN TestMoveWithIgnoreExisting run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-cehowil2kivu'", Local "Local file system at /tmp/rclone251320568", Modify Window "1ms" 2025/02/13 04:31:15 DEBUG : existing: Need to transfer - File not found at Destination 2025/02/13 04:31:15 DEBUG : existing-b: Need to transfer - File not found at Destination 2025/02/13 04:31:15 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-cehowil2kivu': Waiting for checks to finish 2025/02/13 04:31:15 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-cehowil2kivu': Waiting for transfers to finish 2025/02/13 04:31:16 DEBUG : existing-b: md5 = e0249369b3f4f05f11952da8310639cb OK 2025/02/13 04:31:16 INFO : existing-b: Copied (new) 2025/02/13 04:31:16 INFO : existing-b: Deleted 2025/02/13 04:31:17 DEBUG : existing: md5 = 91b0ff3baa69b1f2088fcc71c84c761d OK 2025/02/13 04:31:17 INFO : existing: Copied (new) 2025/02/13 04:31:17 INFO : existing: Deleted 2025/02/13 04:31:17 DEBUG : existing: Destination exists, skipping 2025/02/13 04:31:17 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-cehowil2kivu': Waiting for checks to finish 2025/02/13 04:31:17 DEBUG : existing: Not removing source file as destination file exists and --ignore-existing is set 2025/02/13 04:31:17 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-cehowil2kivu': Waiting for transfers to finish 2025/02/13 04:31:17 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-cehowil2kivu'", Local "Local file system at /tmp/rclone251320568", Modify Window "1ms" --- PASS: TestMoveWithIgnoreExisting (4.49s) === RUN TestServerSideMove run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-cehowil2kivu'", Local "Local file system at /tmp/rclone251320568", Modify Window "1ms" 2025/02/13 04:31:19 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-vifuday8dedo" 2025/02/13 04:31:19 DEBUG : Creating backend with remote "TestDrive:crypt/vkjr0ceqs3tv3o6k67oh9r0hap9k2aj8i6rvoqnq32vbi2b5c130" 2025/02/13 04:31:22 DEBUG : potato2: md5 = 9806e53d572130591bedd22685efc32f OK 2025/02/13 04:31:23 DEBUG : empty space: md5 = 11f84f6131ac5f3797726c58aaebc08b OK 2025/02/13 04:31:25 DEBUG : potato3: md5 = 5c58afd4b57ae2393129c85befe03235 OK sync_test.go:1705: Server side move (if possible) Encrypted drive 'TestCryptDrive:rclone-test-cehowil2kivu' -> Encrypted drive 'TestCryptDrive:rclone-test-vifuday8dedo' 2025/02/13 04:31:27 DEBUG : empty space: md5 = 44fa79d060c7160b5b9b9068f988186b OK 2025/02/13 04:31:29 DEBUG : potato3: md5 = b537afbd82738fbd3ad4efdb0dacb07c OK 2025/02/13 04:31:29 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vifuday8dedo': Using server-side directory move 2025/02/13 04:31:29 INFO : Encrypted drive 'TestCryptDrive:rclone-test-vifuday8dedo': Server side directory move failed - fallback to file moves: can't copy directory - destination already exists 2025/02/13 04:31:29 DEBUG : potato2: Need to transfer - File not found at Destination 2025/02/13 04:31:29 DEBUG : empty space: Size and modification time the same (differ by 0s, within tolerance 1ms) 2025/02/13 04:31:29 DEBUG : empty space: Unchanged skipping 2025/02/13 04:31:29 DEBUG : potato3: Sizes differ (src 68 vs dst 60) 2025/02/13 04:31:29 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vifuday8dedo': Waiting for checks to finish 2025/02/13 04:31:30 INFO : potato3: Deleted 2025/02/13 04:31:30 INFO : empty space: Deleted 2025/02/13 04:31:30 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vifuday8dedo': Waiting for transfers to finish 2025/02/13 04:31:30 INFO : potato2: Moved (server-side) 2025/02/13 04:31:30 INFO : potato3: Moved (server-side) 2025/02/13 04:31:31 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-quqevos8deqe" 2025/02/13 04:31:31 DEBUG : Creating backend with remote "TestDrive:crypt/m0g7k68s544avir6hddf0fk67rr05098u4nokmd8auosf3a272v0" 2025/02/13 04:31:32 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-quqevos8deqe': Using server-side directory move 2025/02/13 04:31:32 INFO : Encrypted drive 'TestCryptDrive:rclone-test-quqevos8deqe': Server side directory move succeeded 2025/02/13 04:31:33 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-quqevos8deqe': Purge remote 2025/02/13 04:31:34 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vifuday8dedo': Purge remote 2025/02/13 04:31:34 NOTICE: purge failed: directory not found --- PASS: TestServerSideMove (15.08s) === RUN TestServerSideMoveWithFilter run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-cehowil2kivu'", Local "Local file system at /tmp/rclone251320568", Modify Window "1ms" 2025/02/13 04:31:35 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-xeralex5lojo" 2025/02/13 04:31:35 DEBUG : Creating backend with remote "TestDrive:crypt/a7o7prl7b3vmol8dgari6ou6dqj1b7h64d60ioiajnvcsv9si2u0" 2025/02/13 04:31:37 DEBUG : potato2: md5 = b8b7441e526a5b74dd78a66f3e1bf937 OK 2025/02/13 04:31:39 DEBUG : empty space: md5 = facf1a8124fd29671cfd88e44a8ab523 OK 2025/02/13 04:31:40 DEBUG : potato3: md5 = d242f06e9e069958dc9918f7717ad482 OK sync_test.go:1705: Server side move (if possible) Encrypted drive 'TestCryptDrive:rclone-test-cehowil2kivu' -> Encrypted drive 'TestCryptDrive:rclone-test-xeralex5lojo' 2025/02/13 04:31:42 DEBUG : empty space: md5 = 892f7e18cb2838d5a3337b0a9d681773 OK 2025/02/13 04:31:44 DEBUG : potato3: md5 = 6d6578bc75c03d47ad41f58bacb147f1 OK 2025/02/13 04:31:44 DEBUG : empty space: Excluded (Size Filter) 2025/02/13 04:31:44 DEBUG : empty space: Excluded 2025/02/13 04:31:44 DEBUG : empty space: Excluded (Size Filter) 2025/02/13 04:31:44 DEBUG : empty space: Excluded 2025/02/13 04:31:44 DEBUG : potato2: Need to transfer - File not found at Destination 2025/02/13 04:31:44 DEBUG : potato3: Sizes differ (src 68 vs dst 60) 2025/02/13 04:31:44 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-xeralex5lojo': Waiting for checks to finish 2025/02/13 04:31:44 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-xeralex5lojo': Waiting for transfers to finish 2025/02/13 04:31:45 INFO : potato3: Deleted 2025/02/13 04:31:45 INFO : potato2: Moved (server-side) 2025/02/13 04:31:45 INFO : potato3: Moved (server-side) 2025/02/13 04:31:46 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-poferon4toli" 2025/02/13 04:31:46 DEBUG : Creating backend with remote "TestDrive:crypt/ne4hkj3ubil65rf61ako96agbav25fs2je6u2ms3kg0q2cqjk3m0" 2025/02/13 04:31:47 DEBUG : empty space: Excluded (Size Filter) 2025/02/13 04:31:47 DEBUG : empty space: Excluded 2025/02/13 04:31:47 DEBUG : potato2: Need to transfer - File not found at Destination 2025/02/13 04:31:47 DEBUG : potato3: Need to transfer - File not found at Destination 2025/02/13 04:31:47 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-poferon4toli': Waiting for checks to finish 2025/02/13 04:31:47 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-poferon4toli': Waiting for transfers to finish 2025/02/13 04:31:48 INFO : potato2: Moved (server-side) 2025/02/13 04:31:49 INFO : potato3: Moved (server-side) 2025/02/13 04:31:49 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-poferon4toli': Purge remote 2025/02/13 04:31:50 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-xeralex5lojo': Purge remote --- PASS: TestServerSideMoveWithFilter (16.51s) === RUN TestServerSideMoveDeleteEmptySourceDirs run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-cehowil2kivu'", Local "Local file system at /tmp/rclone251320568", Modify Window "1ms" 2025/02/13 04:31:51 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-xoxodoy3yupe" 2025/02/13 04:31:51 DEBUG : Creating backend with remote "TestDrive:crypt/l1hncud0qnidtajsvf7ajla8q0lq8td9oh9ve6mu6bgie605vvrg" 2025/02/13 04:31:53 DEBUG : potato2: md5 = 39e41b7bcb7802fdaffb48521dd91eac OK 2025/02/13 04:31:55 DEBUG : empty space: md5 = 177c9b2a0b4a552f7ec27ad270b3b03d OK 2025/02/13 04:31:56 DEBUG : potato3: md5 = 492510bc7d5ebaadf9d270b62ca96120 OK 2025/02/13 04:31:56 INFO : tomatoDir: Making directory sync_test.go:1705: Server side move (if possible) Encrypted drive 'TestCryptDrive:rclone-test-cehowil2kivu' -> Encrypted drive 'TestCryptDrive:rclone-test-xoxodoy3yupe' 2025/02/13 04:31:59 DEBUG : empty space: md5 = 43cb746f0dad37a0f91deb98bca775a1 OK 2025/02/13 04:32:01 DEBUG : potato3: md5 = 17d2f2fbac946733e6c65d616dd62d40 OK 2025/02/13 04:32:01 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-xoxodoy3yupe': Using server-side directory move 2025/02/13 04:32:01 INFO : Encrypted drive 'TestCryptDrive:rclone-test-xoxodoy3yupe': Server side directory move failed - fallback to file moves: can't copy directory - destination already exists 2025/02/13 04:32:01 DEBUG : potato2: Need to transfer - File not found at Destination 2025/02/13 04:32:01 DEBUG : Added delayed dir = "tomatoDir", newDst= 2025/02/13 04:32:01 DEBUG : empty space: Size and modification time the same (differ by 0s, within tolerance 1ms) 2025/02/13 04:32:01 DEBUG : empty space: Unchanged skipping 2025/02/13 04:32:01 DEBUG : potato3: Sizes differ (src 68 vs dst 60) 2025/02/13 04:32:01 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-xoxodoy3yupe': Waiting for checks to finish 2025/02/13 04:32:02 INFO : potato3: Deleted 2025/02/13 04:32:02 INFO : empty space: Deleted 2025/02/13 04:32:02 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-xoxodoy3yupe': Waiting for transfers to finish 2025/02/13 04:32:02 INFO : potato2: Moved (server-side) 2025/02/13 04:32:02 INFO : potato3: Moved (server-side) 2025/02/13 04:32:02 INFO : tomatoDir: Removing directory 2025/02/13 04:32:03 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-cehowil2kivu': deleted 1 directories 2025/02/13 04:32:04 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-zacokuk1qalu" 2025/02/13 04:32:04 DEBUG : Creating backend with remote "TestDrive:crypt/t8dbclduvdect4u75karn842l3sdhrlhd5g7osq1eqvbvbceb5v0" 2025/02/13 04:32:05 INFO : tomatoDir: Making directory 2025/02/13 04:32:06 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zacokuk1qalu': Using server-side directory move 2025/02/13 04:32:06 INFO : Encrypted drive 'TestCryptDrive:rclone-test-zacokuk1qalu': Server side directory move succeeded 2025/02/13 04:32:08 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zacokuk1qalu': Purge remote 2025/02/13 04:32:08 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-xoxodoy3yupe': Purge remote 2025/02/13 04:32:08 NOTICE: purge failed: directory not found --- PASS: TestServerSideMoveDeleteEmptySourceDirs (17.80s) === RUN TestServerSideMoveOverlap run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-cehowil2kivu'", Local "Local file system at /tmp/rclone251320568", Modify Window "1ms" sync_test.go:1910: Skipping test as remote supports DirMove --- SKIP: TestServerSideMoveOverlap (0.59s) === RUN TestSyncOverlap run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-cehowil2kivu'", Local "Local file system at /tmp/rclone251320568", Modify Window "1ms" 2025/02/13 04:32:09 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-cehowil2kivu/rclone-sync-test" 2025/02/13 04:32:09 DEBUG : Creating backend with remote "TestDrive:crypt/2taekpjjreop3k6cmt0r4mp4qbpg9lhqqk3ep1qfmvlh1ctr5r5g/i7355aa0sb89uagn75vfjqr6s3e3e1h2et8in57abn1fe8qfego0" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-cehowil2kivu'", Local "Local file system at /tmp/rclone251320568", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-cehowil2kivu'", Local "Local file system at /tmp/rclone251320568", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-cehowil2kivu'", Local "Local file system at /tmp/rclone251320568", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-cehowil2kivu'", Local "Local file system at /tmp/rclone251320568", Modify Window "1ms" --- PASS: TestSyncOverlap (3.85s) === RUN TestSyncOverlapWithFilter run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-cehowil2kivu'", Local "Local file system at /tmp/rclone251320568", Modify Window "1ms" 2025/02/13 04:32:13 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-cehowil2kivu/rclone-sync-test" 2025/02/13 04:32:13 DEBUG : Creating backend with remote "TestDrive:crypt/2taekpjjreop3k6cmt0r4mp4qbpg9lhqqk3ep1qfmvlh1ctr5r5g/i7355aa0sb89uagn75vfjqr6s3e3e1h2et8in57abn1fe8qfego0" 2025/02/13 04:32:16 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-cehowil2kivu/rclone-sync-test-include/layer2" 2025/02/13 04:32:16 DEBUG : Creating backend with remote "TestDrive:crypt/2taekpjjreop3k6cmt0r4mp4qbpg9lhqqk3ep1qfmvlh1ctr5r5g/khf2vlblvnbf9ftevqm0htmss73hj1j5a7q328e4ohrgs7e2loe0/n01jpl9202nn9ec1rb75h0f1c4" 2025/02/13 04:32:19 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-cehowil2kivu/rclone-sync-test-ignore-file" 2025/02/13 04:32:19 DEBUG : Creating backend with remote "TestDrive:crypt/2taekpjjreop3k6cmt0r4mp4qbpg9lhqqk3ep1qfmvlh1ctr5r5g/kmf11jujl9uha3tjganvgpkn45bu778hb5vb5riug1c26b38k7sg" 2025/02/13 04:32:23 DEBUG : rclone-sync-test-ignore-file/.ignore: md5 = 339c73300973adb9d1d59090bad991a9 OK 2025/02/13 04:32:24 DEBUG : rclone-sync-test-ignore-file: Excluded 2025/02/13 04:32:24 DEBUG : rclone-sync-test: Excluded 2025/02/13 04:32:24 DEBUG : Added delayed dir = "rclone-sync-test-include", newDst= 2025/02/13 04:32:25 DEBUG : rclone-sync-test-include/layer2: Excluded 2025/02/13 04:32:25 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-cehowil2kivu/rclone-sync-test': Waiting for checks to finish 2025/02/13 04:32:25 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-cehowil2kivu/rclone-sync-test': Waiting for transfers to finish 2025/02/13 04:32:25 DEBUG : Waiting for deletions to finish 2025/02/13 04:32:25 INFO : There was nothing to transfer 2025/02/13 04:32:25 DEBUG : rclone-sync-test-ignore-file: Excluded 2025/02/13 04:32:26 DEBUG : rclone-sync-test: Excluded 2025/02/13 04:32:26 DEBUG : rclone-sync-test-include/layer2: Excluded 2025/02/13 04:32:26 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-cehowil2kivu': Waiting for checks to finish 2025/02/13 04:32:26 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-cehowil2kivu': Waiting for transfers to finish 2025/02/13 04:32:26 DEBUG : Waiting for deletions to finish 2025/02/13 04:32:26 INFO : rclone-sync-test-include: Removing directory 2025/02/13 04:32:27 DEBUG : khf2vlblvnbf9ftevqm0htmss73hj1j5a7q328e4ohrgs7e2loe0: Rmdir: contains file: "n01jpl9202nn9ec1rb75h0f1c4" 2025/02/13 04:32:27 DEBUG : rclone-sync-test-include: Failed to Rmdir: directory not empty 2025/02/13 04:32:27 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-cehowil2kivu': failed to delete 1 directories 2025/02/13 04:32:27 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-cehowil2kivu'", Local "Local file system at /tmp/rclone251320568", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-cehowil2kivu'", Local "Local file system at /tmp/rclone251320568", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-cehowil2kivu'", Local "Local file system at /tmp/rclone251320568", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-cehowil2kivu'", Local "Local file system at /tmp/rclone251320568", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-cehowil2kivu'", Local "Local file system at /tmp/rclone251320568", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-cehowil2kivu'", Local "Local file system at /tmp/rclone251320568", Modify Window "1ms" 2025/02/13 04:32:27 DEBUG : rclone-sync-test-ignore-file: Excluded 2025/02/13 04:32:28 DEBUG : rclone-sync-test: Excluded 2025/02/13 04:32:28 DEBUG : Added delayed dir = "rclone-sync-test-include", newDst= 2025/02/13 04:32:28 DEBUG : rclone-sync-test-include/layer2: Excluded 2025/02/13 04:32:28 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-cehowil2kivu/rclone-sync-test-include/layer2': Waiting for checks to finish 2025/02/13 04:32:28 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-cehowil2kivu/rclone-sync-test-include/layer2': Waiting for transfers to finish 2025/02/13 04:32:28 DEBUG : Waiting for deletions to finish 2025/02/13 04:32:28 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-cehowil2kivu'", Local "Local file system at /tmp/rclone251320568", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-cehowil2kivu'", Local "Local file system at /tmp/rclone251320568", Modify Window "1ms" 2025/02/13 04:32:29 DEBUG : rclone-sync-test-ignore-file: Excluded 2025/02/13 04:32:29 DEBUG : rclone-sync-test: Excluded 2025/02/13 04:32:30 DEBUG : rclone-sync-test-include/layer2: Excluded 2025/02/13 04:32:30 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-cehowil2kivu': Waiting for checks to finish 2025/02/13 04:32:30 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-cehowil2kivu': Waiting for transfers to finish 2025/02/13 04:32:30 DEBUG : Waiting for deletions to finish 2025/02/13 04:32:30 INFO : rclone-sync-test-include: Removing directory 2025/02/13 04:32:30 DEBUG : khf2vlblvnbf9ftevqm0htmss73hj1j5a7q328e4ohrgs7e2loe0: Rmdir: contains file: "n01jpl9202nn9ec1rb75h0f1c4" 2025/02/13 04:32:30 DEBUG : rclone-sync-test-include: Failed to Rmdir: directory not empty 2025/02/13 04:32:30 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-cehowil2kivu': failed to delete 1 directories 2025/02/13 04:32:30 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-cehowil2kivu'", Local "Local file system at /tmp/rclone251320568", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-cehowil2kivu'", Local "Local file system at /tmp/rclone251320568", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-cehowil2kivu'", Local "Local file system at /tmp/rclone251320568", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-cehowil2kivu'", Local "Local file system at /tmp/rclone251320568", Modify Window "1ms" 2025/02/13 04:32:31 DEBUG : : Excluded 2025/02/13 04:32:31 DEBUG : rclone-sync-test-ignore-file: Excluded 2025/02/13 04:32:31 DEBUG : rclone-sync-test: Excluded 2025/02/13 04:32:31 DEBUG : Added delayed dir = "rclone-sync-test-include", newDst= 2025/02/13 04:32:32 DEBUG : rclone-sync-test-include/layer2: Excluded 2025/02/13 04:32:32 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-cehowil2kivu/rclone-sync-test-ignore-file': Waiting for checks to finish 2025/02/13 04:32:32 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-cehowil2kivu/rclone-sync-test-ignore-file': Waiting for transfers to finish 2025/02/13 04:32:32 DEBUG : Waiting for deletions to finish 2025/02/13 04:32:32 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-cehowil2kivu'", Local "Local file system at /tmp/rclone251320568", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-cehowil2kivu'", Local "Local file system at /tmp/rclone251320568", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-cehowil2kivu'", Local "Local file system at /tmp/rclone251320568", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-cehowil2kivu'", Local "Local file system at /tmp/rclone251320568", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-cehowil2kivu'", Local "Local file system at /tmp/rclone251320568", Modify Window "1ms" 2025/02/13 04:32:34 DEBUG : khf2vlblvnbf9ftevqm0htmss73hj1j5a7q328e4ohrgs7e2loe0: Rmdir: contains trashed file: "n01jpl9202nn9ec1rb75h0f1c4" 2025/02/13 04:32:35 DEBUG : kmf11jujl9uha3tjganvgpkn45bu778hb5vb5riug1c26b38k7sg: Rmdir: contains trashed file: "i0t74httmdlljg425j6tg570d8" --- PASS: TestSyncOverlapWithFilter (30.79s) === RUN TestSyncCompareDest run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-cehowil2kivu'", Local "Local file system at /tmp/rclone251320568", Modify Window "1ms" 2025/02/13 04:32:44 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-cehowil2kivu/dst" 2025/02/13 04:32:44 DEBUG : Creating backend with remote "TestDrive:crypt/2taekpjjreop3k6cmt0r4mp4qbpg9lhqqk3ep1qfmvlh1ctr5r5g/31u3jie661vd5p8j7rtc3hgbh0" 2025/02/13 04:32:46 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-cehowil2kivu/CompareDest" 2025/02/13 04:32:46 DEBUG : Creating backend with remote "TestDrive:crypt/2taekpjjreop3k6cmt0r4mp4qbpg9lhqqk3ep1qfmvlh1ctr5r5g/gveqi14airsml4bgu7krj116o8" 2025/02/13 04:32:48 DEBUG : one: Need to transfer - File not found at Destination 2025/02/13 04:32:48 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-cehowil2kivu/dst': Waiting for checks to finish 2025/02/13 04:32:48 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-cehowil2kivu/dst': Waiting for transfers to finish 2025/02/13 04:32:50 DEBUG : one: md5 = af6984685e0dd97f6da5c0f6b3ec37cd OK 2025/02/13 04:32:50 INFO : one: Copied (new) 2025/02/13 04:32:50 DEBUG : Waiting for deletions to finish 2025/02/13 04:32:51 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-cehowil2kivu/dst': Waiting for checks to finish 2025/02/13 04:32:51 DEBUG : one: Sizes differ (src 5 vs dst 3) 2025/02/13 04:32:51 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-cehowil2kivu/dst': Waiting for transfers to finish 2025/02/13 04:32:53 DEBUG : one: md5 = 23f2fcc20d0143065512022af1338d78 OK 2025/02/13 04:32:53 INFO : one: Copied (replaced existing) 2025/02/13 04:32:53 DEBUG : Waiting for deletions to finish 2025/02/13 04:32:55 DEBUG : dst/one: md5 = c783b84eed12d6a32a546093b667f012 OK 2025/02/13 04:32:57 DEBUG : CompareDest/one: md5 = 5b616f000cf72a5e34a2661a28e314ad OK 2025/02/13 04:32:58 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-cehowil2kivu/dst': Waiting for checks to finish 2025/02/13 04:32:58 DEBUG : one: Sizes differ (src 5 vs dst 3) 2025/02/13 04:32:58 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/02/13 04:32:58 DEBUG : one: Destination found in --compare-dest, skipping 2025/02/13 04:32:58 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-cehowil2kivu/dst': Waiting for transfers to finish 2025/02/13 04:32:58 DEBUG : Waiting for deletions to finish 2025/02/13 04:32:58 INFO : There was nothing to transfer 2025/02/13 04:33:00 DEBUG : CompareDest/two: md5 = 6f2bd4d57ded2ffe7bd60a8045f380fc OK 2025/02/13 04:33:01 DEBUG : two: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/02/13 04:33:01 DEBUG : two: Destination found in --compare-dest, skipping 2025/02/13 04:33:01 DEBUG : one: Sizes differ (src 5 vs dst 3) 2025/02/13 04:33:01 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-cehowil2kivu/dst': Waiting for checks to finish 2025/02/13 04:33:01 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/02/13 04:33:01 DEBUG : one: Destination found in --compare-dest, skipping 2025/02/13 04:33:01 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-cehowil2kivu/dst': Waiting for transfers to finish 2025/02/13 04:33:01 DEBUG : Waiting for deletions to finish 2025/02/13 04:33:01 INFO : There was nothing to transfer 2025/02/13 04:33:02 DEBUG : two: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/02/13 04:33:02 DEBUG : two: Destination found in --compare-dest, skipping 2025/02/13 04:33:02 DEBUG : one: Sizes differ (src 5 vs dst 3) 2025/02/13 04:33:02 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-cehowil2kivu/dst': Waiting for checks to finish 2025/02/13 04:33:03 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/02/13 04:33:03 DEBUG : one: Destination found in --compare-dest, skipping 2025/02/13 04:33:03 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-cehowil2kivu/dst': Waiting for transfers to finish 2025/02/13 04:33:03 DEBUG : Waiting for deletions to finish 2025/02/13 04:33:03 INFO : There was nothing to transfer sync_test.go:2175: No hash on uploaded file so skipping compare timestamp test 2025/02/13 04:33:04 DEBUG : two: Sizes differ (src 5 vs dst 3) 2025/02/13 04:33:04 DEBUG : two: Need to transfer - File not found at Destination 2025/02/13 04:33:04 DEBUG : one: Sizes differ (src 5 vs dst 3) 2025/02/13 04:33:04 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-cehowil2kivu/dst': Waiting for checks to finish 2025/02/13 04:33:04 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/02/13 04:33:04 DEBUG : one: Destination found in --compare-dest, skipping 2025/02/13 04:33:04 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-cehowil2kivu/dst': Waiting for transfers to finish 2025/02/13 04:33:06 DEBUG : two: md5 = 7edea8f943bcbbb00b08f4136d304503 OK 2025/02/13 04:33:06 INFO : two: Copied (new) 2025/02/13 04:33:06 DEBUG : Waiting for deletions to finish 2025/02/13 04:33:09 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k" 2025/02/13 04:33:09 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" 2025/02/13 04:33:10 DEBUG : gveqi14airsml4bgu7krj116o8: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k" 2025/02/13 04:33:10 DEBUG : gveqi14airsml4bgu7krj116o8: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" --- PASS: TestSyncCompareDest (26.50s) === RUN TestSyncMultipleCompareDest run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-cehowil2kivu'", Local "Local file system at /tmp/rclone251320568", Modify Window "1ms" 2025/02/13 04:33:13 DEBUG : pre-dest1/1: md5 = b381427f2751c9be0bda8bf4ab9f7a1a OK 2025/02/13 04:33:15 DEBUG : pre-dest2/2: md5 = 4b806f988045d6697e49ec97422c1cd5 OK 2025/02/13 04:33:16 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-cehowil2kivu/dest" 2025/02/13 04:33:16 DEBUG : Creating backend with remote "TestDrive:crypt/2taekpjjreop3k6cmt0r4mp4qbpg9lhqqk3ep1qfmvlh1ctr5r5g/rg03c1jvnehrrc617i0lnqjddc" 2025/02/13 04:33:17 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-cehowil2kivu/pre-dest1" 2025/02/13 04:33:17 DEBUG : Creating backend with remote "TestDrive:crypt/2taekpjjreop3k6cmt0r4mp4qbpg9lhqqk3ep1qfmvlh1ctr5r5g/bbnblvh6k061ssopqrp18kd7gc" 2025/02/13 04:33:18 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-cehowil2kivu/pre-dest2" 2025/02/13 04:33:18 DEBUG : Creating backend with remote "TestDrive:crypt/2taekpjjreop3k6cmt0r4mp4qbpg9lhqqk3ep1qfmvlh1ctr5r5g/dgicm1h6b5ejvlltm8eeif0bnk" 2025/02/13 04:33:19 DEBUG : 1: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/02/13 04:33:19 DEBUG : 1: Destination found in --compare-dest, skipping 2025/02/13 04:33:20 DEBUG : 2: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/02/13 04:33:20 DEBUG : 2: Destination found in --compare-dest, skipping 2025/02/13 04:33:20 DEBUG : 3: Need to transfer - File not found at Destination 2025/02/13 04:33:20 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-cehowil2kivu/dest': Waiting for checks to finish 2025/02/13 04:33:20 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-cehowil2kivu/dest': Waiting for transfers to finish 2025/02/13 04:33:22 DEBUG : 3: md5 = ba52e3413798870cfc3995fc6e80beaa OK 2025/02/13 04:33:22 INFO : 3: Copied (new) 2025/02/13 04:33:22 DEBUG : Waiting for deletions to finish 2025/02/13 04:33:25 DEBUG : dgicm1h6b5ejvlltm8eeif0bnk: Rmdir: contains trashed file: "1ghu8geql9vrl726n32nrf65bc" 2025/02/13 04:33:26 DEBUG : bbnblvh6k061ssopqrp18kd7gc: Rmdir: contains trashed file: "skbfko3oil7es0lj68ob574sro" 2025/02/13 04:33:27 DEBUG : rg03c1jvnehrrc617i0lnqjddc: Rmdir: contains trashed file: "g072p7hmjchlnj0gibe64c1epg" --- PASS: TestSyncMultipleCompareDest (16.82s) === RUN TestSyncCopyDest run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-cehowil2kivu'", Local "Local file system at /tmp/rclone251320568", Modify Window "1ms" 2025/02/13 04:33:27 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-cehowil2kivu/dst" 2025/02/13 04:33:27 DEBUG : Creating backend with remote "TestDrive:crypt/2taekpjjreop3k6cmt0r4mp4qbpg9lhqqk3ep1qfmvlh1ctr5r5g/31u3jie661vd5p8j7rtc3hgbh0" 2025/02/13 04:33:29 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-cehowil2kivu/CopyDest" 2025/02/13 04:33:29 DEBUG : Creating backend with remote "TestDrive:crypt/2taekpjjreop3k6cmt0r4mp4qbpg9lhqqk3ep1qfmvlh1ctr5r5g/d09o6po3f7bm6ce32vdgs8h9ls" 2025/02/13 04:33:31 DEBUG : one: Need to transfer - File not found at Destination 2025/02/13 04:33:31 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-cehowil2kivu/dst': Waiting for checks to finish 2025/02/13 04:33:31 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-cehowil2kivu/dst': Waiting for transfers to finish 2025/02/13 04:33:33 DEBUG : one: md5 = a82dac58345a26904be210154a672f27 OK 2025/02/13 04:33:33 INFO : one: Copied (new) 2025/02/13 04:33:33 DEBUG : Waiting for deletions to finish 2025/02/13 04:33:34 DEBUG : one: Sizes differ (src 5 vs dst 3) 2025/02/13 04:33:34 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-cehowil2kivu/dst': Waiting for checks to finish 2025/02/13 04:33:35 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-cehowil2kivu/dst': Waiting for transfers to finish 2025/02/13 04:33:36 DEBUG : one: md5 = d436dd3aaa09bc7e913308ebe59bcdb6 OK 2025/02/13 04:33:36 INFO : one: Copied (replaced existing) 2025/02/13 04:33:36 DEBUG : Waiting for deletions to finish 2025/02/13 04:33:38 DEBUG : dst/one: md5 = dda3da5383a269be5ce151352eb2f585 OK 2025/02/13 04:33:40 DEBUG : CopyDest/one: md5 = 2fe8fecf43f1b2b63b9903fa1afaf7b1 OK 2025/02/13 04:33:40 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-cehowil2kivu/BackupDir" 2025/02/13 04:33:40 DEBUG : Creating backend with remote "TestDrive:crypt/2taekpjjreop3k6cmt0r4mp4qbpg9lhqqk3ep1qfmvlh1ctr5r5g/s6dbk3lfi7c9kfvo6j7bla9m0g" 2025/02/13 04:33:42 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-cehowil2kivu/dst': Waiting for checks to finish 2025/02/13 04:33:42 DEBUG : one: Sizes differ (src 5 vs dst 3) 2025/02/13 04:33:43 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/02/13 04:33:43 DEBUG : one: Sizes differ (src 5 vs dst 3) 2025/02/13 04:33:44 INFO : one: Moved (server-side) 2025/02/13 04:33:45 INFO : one: Copied (server-side copy) 2025/02/13 04:33:45 DEBUG : one: Destination found in --copy-dest, using server-side copy 2025/02/13 04:33:45 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-cehowil2kivu/dst': Waiting for transfers to finish 2025/02/13 04:33:45 DEBUG : Waiting for deletions to finish 2025/02/13 04:33:47 DEBUG : CopyDest/two: md5 = a865c3540032caed2b49158c6df5d228 OK 2025/02/13 04:33:48 DEBUG : two: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/02/13 04:33:49 INFO : two: Copied (server-side copy) 2025/02/13 04:33:49 DEBUG : two: Destination found in --copy-dest, using server-side copy 2025/02/13 04:33:49 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/02/13 04:33:49 DEBUG : one: Unchanged skipping 2025/02/13 04:33:49 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-cehowil2kivu/dst': Waiting for checks to finish 2025/02/13 04:33:49 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-cehowil2kivu/dst': Waiting for transfers to finish 2025/02/13 04:33:49 DEBUG : Waiting for deletions to finish 2025/02/13 04:33:50 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/02/13 04:33:50 DEBUG : one: Unchanged skipping 2025/02/13 04:33:50 DEBUG : two: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/02/13 04:33:50 DEBUG : two: Unchanged skipping 2025/02/13 04:33:50 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-cehowil2kivu/dst': Waiting for checks to finish 2025/02/13 04:33:50 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-cehowil2kivu/dst': Waiting for transfers to finish 2025/02/13 04:33:50 DEBUG : Waiting for deletions to finish 2025/02/13 04:33:50 INFO : There was nothing to transfer 2025/02/13 04:33:52 DEBUG : CopyDest/three: md5 = 81380b5cedb6b222d3dfe7734a9734d7 OK 2025/02/13 04:33:53 DEBUG : three: Sizes differ (src 7 vs dst 5) 2025/02/13 04:33:53 DEBUG : three: Destination not found in --copy-dest 2025/02/13 04:33:53 DEBUG : three: Need to transfer - File not found at Destination 2025/02/13 04:33:53 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/02/13 04:33:53 DEBUG : two: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/02/13 04:33:53 DEBUG : one: Unchanged skipping 2025/02/13 04:33:53 DEBUG : two: Unchanged skipping 2025/02/13 04:33:53 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-cehowil2kivu/dst': Waiting for checks to finish 2025/02/13 04:33:53 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-cehowil2kivu/dst': Waiting for transfers to finish 2025/02/13 04:33:54 DEBUG : three: md5 = b72d81946871a727bdf75c2db5500afa OK 2025/02/13 04:33:54 INFO : three: Copied (new) 2025/02/13 04:33:54 DEBUG : Waiting for deletions to finish 2025/02/13 04:33:59 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "b6jdmn2b1adrhc8vikh7edr9os" 2025/02/13 04:33:59 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k" 2025/02/13 04:33:59 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" 2025/02/13 04:33:59 DEBUG : d09o6po3f7bm6ce32vdgs8h9ls: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" 2025/02/13 04:33:59 DEBUG : d09o6po3f7bm6ce32vdgs8h9ls: Rmdir: contains trashed file: "b6jdmn2b1adrhc8vikh7edr9os" 2025/02/13 04:33:59 DEBUG : d09o6po3f7bm6ce32vdgs8h9ls: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k" 2025/02/13 04:34:00 DEBUG : s6dbk3lfi7c9kfvo6j7bla9m0g: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" --- PASS: TestSyncCopyDest (33.47s) === RUN TestSyncBackupDir run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-cehowil2kivu'", Local "Local file system at /tmp/rclone251320568", Modify Window "1ms" 2025/02/13 04:34:03 DEBUG : dst/one: md5 = 8768d2eea9b4bcad23576143bc1918a1 OK 2025/02/13 04:34:05 DEBUG : dst/two: md5 = a1c3b0ac117739b858915d9277281e97 OK 2025/02/13 04:34:06 DEBUG : dst/three.txt: md5 = d98985055e5e8a387135ca59df1bfaf0 OK 2025/02/13 04:34:06 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-cehowil2kivu/dst" 2025/02/13 04:34:07 DEBUG : Creating backend with remote "TestDrive:crypt/2taekpjjreop3k6cmt0r4mp4qbpg9lhqqk3ep1qfmvlh1ctr5r5g/31u3jie661vd5p8j7rtc3hgbh0" 2025/02/13 04:34:07 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-cehowil2kivu/backup" 2025/02/13 04:34:07 DEBUG : Creating backend with remote "TestDrive:crypt/2taekpjjreop3k6cmt0r4mp4qbpg9lhqqk3ep1qfmvlh1ctr5r5g/1nrff024r7pq65ecp72fc28jb0" 2025/02/13 04:34:09 DEBUG : one: Sizes differ (src 4 vs dst 3) 2025/02/13 04:34:09 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/02/13 04:34:09 DEBUG : two: Unchanged skipping 2025/02/13 04:34:09 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-cehowil2kivu/dst': Waiting for checks to finish 2025/02/13 04:34:11 INFO : one: Moved (server-side) 2025/02/13 04:34:11 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-cehowil2kivu/dst': Waiting for transfers to finish 2025/02/13 04:34:12 DEBUG : one: md5 = 28f14dc6b88b0e3b52846c7bac395a69 OK 2025/02/13 04:34:12 INFO : one: Copied (new) 2025/02/13 04:34:12 DEBUG : Waiting for deletions to finish 2025/02/13 04:34:13 INFO : three.txt: Moved (server-side) 2025/02/13 04:34:13 INFO : three.txt: Moved into backup dir 2025/02/13 04:34:15 DEBUG : dst/three.txt: md5 = d1856b911f14237adb1c81969f018a7a OK 2025/02/13 04:34:16 DEBUG : one: Sizes differ (src 5 vs dst 4) 2025/02/13 04:34:16 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/02/13 04:34:16 DEBUG : two: Unchanged skipping 2025/02/13 04:34:16 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-cehowil2kivu/dst': Waiting for checks to finish 2025/02/13 04:34:17 INFO : one: Deleted 2025/02/13 04:34:17 INFO : one: Moved (server-side) 2025/02/13 04:34:17 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-cehowil2kivu/dst': Waiting for transfers to finish 2025/02/13 04:34:19 DEBUG : one: md5 = f610bec4c0f99286ff65e3855d8348cc OK 2025/02/13 04:34:19 INFO : one: Copied (new) 2025/02/13 04:34:19 DEBUG : Waiting for deletions to finish 2025/02/13 04:34:20 INFO : three.txt: Deleted 2025/02/13 04:34:20 INFO : three.txt: Moved (server-side) 2025/02/13 04:34:20 INFO : three.txt: Moved into backup dir 2025/02/13 04:34:23 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" 2025/02/13 04:34:23 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k" 2025/02/13 04:34:24 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" 2025/02/13 04:34:24 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "tr2hj63d80ftlmvm6a952snjcc" 2025/02/13 04:34:24 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" 2025/02/13 04:34:24 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "tr2hj63d80ftlmvm6a952snjcc" --- PASS: TestSyncBackupDir (23.79s) === RUN TestSyncBackupDirWithSuffix run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-cehowil2kivu'", Local "Local file system at /tmp/rclone251320568", Modify Window "1ms" 2025/02/13 04:34:27 DEBUG : dst/one: md5 = 9570f79f0193b1a6e875acb9bfa4c23b OK 2025/02/13 04:34:28 DEBUG : dst/two: md5 = f19c6a4fc18a73dacf9cbd70ff2800bd OK 2025/02/13 04:34:29 DEBUG : dst/three.txt: md5 = 675a1f7c590d03629dd374dbc53c46ca OK 2025/02/13 04:34:30 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-cehowil2kivu/dst" 2025/02/13 04:34:30 DEBUG : Creating backend with remote "TestDrive:crypt/2taekpjjreop3k6cmt0r4mp4qbpg9lhqqk3ep1qfmvlh1ctr5r5g/31u3jie661vd5p8j7rtc3hgbh0" 2025/02/13 04:34:31 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-cehowil2kivu/backup" 2025/02/13 04:34:31 DEBUG : Creating backend with remote "TestDrive:crypt/2taekpjjreop3k6cmt0r4mp4qbpg9lhqqk3ep1qfmvlh1ctr5r5g/1nrff024r7pq65ecp72fc28jb0" 2025/02/13 04:34:34 DEBUG : one: Sizes differ (src 4 vs dst 3) 2025/02/13 04:34:34 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/02/13 04:34:34 DEBUG : two: Unchanged skipping 2025/02/13 04:34:34 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-cehowil2kivu/dst': Waiting for checks to finish 2025/02/13 04:34:35 INFO : one: Moved (server-side) to: one.bak 2025/02/13 04:34:35 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-cehowil2kivu/dst': Waiting for transfers to finish 2025/02/13 04:34:36 DEBUG : one: md5 = 7ea2f2e23f64f766d0438775f76eccb1 OK 2025/02/13 04:34:36 INFO : one: Copied (new) 2025/02/13 04:34:36 DEBUG : Waiting for deletions to finish 2025/02/13 04:34:37 INFO : three.txt: Moved (server-side) to: three.txt.bak 2025/02/13 04:34:37 INFO : three.txt: Moved into backup dir 2025/02/13 04:34:39 DEBUG : dst/three.txt: md5 = a03c9fb4f96ef4486e4be5ed0432098c OK 2025/02/13 04:34:40 DEBUG : one: Sizes differ (src 5 vs dst 4) 2025/02/13 04:34:40 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/02/13 04:34:40 DEBUG : two: Unchanged skipping 2025/02/13 04:34:40 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-cehowil2kivu/dst': Waiting for checks to finish 2025/02/13 04:34:41 INFO : one.bak: Deleted 2025/02/13 04:34:41 INFO : one: Moved (server-side) to: one.bak 2025/02/13 04:34:41 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-cehowil2kivu/dst': Waiting for transfers to finish 2025/02/13 04:34:43 DEBUG : one: md5 = ae8936b87a3afef38bfacc1a303722ab OK 2025/02/13 04:34:43 INFO : one: Copied (new) 2025/02/13 04:34:43 DEBUG : Waiting for deletions to finish 2025/02/13 04:34:43 INFO : three.txt.bak: Deleted 2025/02/13 04:34:44 INFO : three.txt: Moved (server-side) to: three.txt.bak 2025/02/13 04:34:44 INFO : three.txt: Moved into backup dir 2025/02/13 04:34:47 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" 2025/02/13 04:34:47 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k" 2025/02/13 04:34:48 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "sk91qgsqfn0r271r2ehsaoc20c" 2025/02/13 04:34:48 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "qltcak2uaegtmcoa8vijdppbp8" 2025/02/13 04:34:48 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "qltcak2uaegtmcoa8vijdppbp8" 2025/02/13 04:34:48 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "sk91qgsqfn0r271r2ehsaoc20c" --- PASS: TestSyncBackupDirWithSuffix (23.67s) === RUN TestSyncBackupDirWithSuffixKeepExtension run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-cehowil2kivu'", Local "Local file system at /tmp/rclone251320568", Modify Window "1ms" 2025/02/13 04:34:50 DEBUG : dst/one: md5 = 6a3e6c36e15fecfdbc2cb3734e6cddb9 OK 2025/02/13 04:34:52 DEBUG : dst/two: md5 = 7a633993d02ecbc899e95fc4a7d2bc16 OK 2025/02/13 04:34:53 DEBUG : dst/three.txt: md5 = 2e173446053c286181c379ac211d0596 OK 2025/02/13 04:34:54 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-cehowil2kivu/dst" 2025/02/13 04:34:54 DEBUG : Creating backend with remote "TestDrive:crypt/2taekpjjreop3k6cmt0r4mp4qbpg9lhqqk3ep1qfmvlh1ctr5r5g/31u3jie661vd5p8j7rtc3hgbh0" 2025/02/13 04:34:55 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-cehowil2kivu/backup" 2025/02/13 04:34:55 DEBUG : Creating backend with remote "TestDrive:crypt/2taekpjjreop3k6cmt0r4mp4qbpg9lhqqk3ep1qfmvlh1ctr5r5g/1nrff024r7pq65ecp72fc28jb0" 2025/02/13 04:34:57 DEBUG : one: Sizes differ (src 4 vs dst 3) 2025/02/13 04:34:57 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-cehowil2kivu/dst': Waiting for checks to finish 2025/02/13 04:34:57 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/02/13 04:34:57 DEBUG : two: Unchanged skipping 2025/02/13 04:34:58 INFO : one: Moved (server-side) to: one-2019-01-01 2025/02/13 04:34:58 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-cehowil2kivu/dst': Waiting for transfers to finish 2025/02/13 04:34:59 DEBUG : one: md5 = 499b19187cfb892bd816f086c79d9920 OK 2025/02/13 04:34:59 INFO : one: Copied (new) 2025/02/13 04:34:59 DEBUG : Waiting for deletions to finish 2025/02/13 04:35:00 INFO : three.txt: Moved (server-side) to: three-2019-01-01.txt 2025/02/13 04:35:00 INFO : three.txt: Moved into backup dir 2025/02/13 04:35:02 DEBUG : dst/three.txt: md5 = a1b2f7ef2a9271c0d52477e9e532e06f OK 2025/02/13 04:35:03 DEBUG : one: Sizes differ (src 5 vs dst 4) 2025/02/13 04:35:03 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/02/13 04:35:03 DEBUG : two: Unchanged skipping 2025/02/13 04:35:03 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-cehowil2kivu/dst': Waiting for checks to finish 2025/02/13 04:35:04 INFO : one-2019-01-01: Deleted 2025/02/13 04:35:04 INFO : one: Moved (server-side) to: one-2019-01-01 2025/02/13 04:35:04 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-cehowil2kivu/dst': Waiting for transfers to finish 2025/02/13 04:35:06 DEBUG : one: md5 = 53378deef7e7386705ead430faef0cfd OK 2025/02/13 04:35:06 INFO : one: Copied (new) 2025/02/13 04:35:06 DEBUG : Waiting for deletions to finish 2025/02/13 04:35:06 INFO : three-2019-01-01.txt: Deleted 2025/02/13 04:35:07 INFO : three.txt: Moved (server-side) to: three-2019-01-01.txt 2025/02/13 04:35:07 INFO : three.txt: Moved into backup dir 2025/02/13 04:35:10 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" 2025/02/13 04:35:10 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k" 2025/02/13 04:35:10 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "qtq2f6qq4lgpsmj88vb7147qje3prudmtfdtr2342fth58vo9a50" 2025/02/13 04:35:10 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "jcjl1bv3ep0v8kt35lqql1co90" 2025/02/13 04:35:10 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "jcjl1bv3ep0v8kt35lqql1co90" 2025/02/13 04:35:10 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "qtq2f6qq4lgpsmj88vb7147qje3prudmtfdtr2342fth58vo9a50" --- PASS: TestSyncBackupDirWithSuffixKeepExtension (22.90s) === RUN TestSyncBackupDirSuffixOnly run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-cehowil2kivu'", Local "Local file system at /tmp/rclone251320568", Modify Window "1ms" 2025/02/13 04:35:13 DEBUG : dst/one: md5 = 61fd127520dbcb9be616492e6b40a646 OK 2025/02/13 04:35:15 DEBUG : dst/two: md5 = d07a944e130cbb020f08c0cefae5302d OK 2025/02/13 04:35:16 DEBUG : dst/three.txt: md5 = 8a4e1da185a0b7ee2d38bf1e4abbb2af OK 2025/02/13 04:35:16 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-cehowil2kivu/dst" 2025/02/13 04:35:17 DEBUG : Creating backend with remote "TestDrive:crypt/2taekpjjreop3k6cmt0r4mp4qbpg9lhqqk3ep1qfmvlh1ctr5r5g/31u3jie661vd5p8j7rtc3hgbh0" 2025/02/13 04:35:18 DEBUG : one: Sizes differ (src 4 vs dst 3) 2025/02/13 04:35:18 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-cehowil2kivu/dst': Waiting for checks to finish 2025/02/13 04:35:18 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/02/13 04:35:18 DEBUG : two: Unchanged skipping 2025/02/13 04:35:18 INFO : one: Moved (server-side) to: one.bak 2025/02/13 04:35:18 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-cehowil2kivu/dst': Waiting for transfers to finish 2025/02/13 04:35:20 DEBUG : one: md5 = b1e24157d7a5c6f3816d437ec660acc6 OK 2025/02/13 04:35:20 INFO : one: Copied (new) 2025/02/13 04:35:20 DEBUG : Waiting for deletions to finish 2025/02/13 04:35:20 INFO : three.txt: Moved (server-side) to: three.txt.bak 2025/02/13 04:35:20 INFO : three.txt: Moved into backup dir 2025/02/13 04:35:22 DEBUG : dst/three.txt: md5 = 918ced0be2a58eacb959d8a1490b202a OK 2025/02/13 04:35:23 DEBUG : three.txt.bak: Excluded (Path Filter) 2025/02/13 04:35:23 DEBUG : three.txt.bak: Excluded 2025/02/13 04:35:23 DEBUG : one.bak: Excluded (Path Filter) 2025/02/13 04:35:23 DEBUG : one.bak: Excluded 2025/02/13 04:35:23 DEBUG : one: Sizes differ (src 5 vs dst 4) 2025/02/13 04:35:23 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/02/13 04:35:23 DEBUG : two: Unchanged skipping 2025/02/13 04:35:23 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-cehowil2kivu/dst': Waiting for checks to finish 2025/02/13 04:35:23 INFO : one.bak: Deleted 2025/02/13 04:35:24 INFO : one: Moved (server-side) to: one.bak 2025/02/13 04:35:24 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-cehowil2kivu/dst': Waiting for transfers to finish 2025/02/13 04:35:25 DEBUG : one: md5 = 29a47c0dd93a0ea9ce251e416e90d3fa OK 2025/02/13 04:35:25 INFO : one: Copied (new) 2025/02/13 04:35:25 DEBUG : Waiting for deletions to finish 2025/02/13 04:35:26 INFO : three.txt.bak: Deleted 2025/02/13 04:35:26 INFO : three.txt: Moved (server-side) to: three.txt.bak 2025/02/13 04:35:26 INFO : three.txt: Moved into backup dir 2025/02/13 04:35:29 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" 2025/02/13 04:35:29 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "qltcak2uaegtmcoa8vijdppbp8" 2025/02/13 04:35:29 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "sk91qgsqfn0r271r2ehsaoc20c" 2025/02/13 04:35:29 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k" 2025/02/13 04:35:29 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "sk91qgsqfn0r271r2ehsaoc20c" 2025/02/13 04:35:29 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "qltcak2uaegtmcoa8vijdppbp8" --- PASS: TestSyncBackupDirSuffixOnly (18.91s) === RUN TestSyncSuffix run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-cehowil2kivu'", Local "Local file system at /tmp/rclone251320568", Modify Window "1ms" 2025/02/13 04:35:32 DEBUG : dst/one: md5 = 19170478125c1c5f0a649937f9ed0212 OK 2025/02/13 04:35:34 DEBUG : dst/two: md5 = c2fdc1bf5bf6a214e563100ff868679e OK 2025/02/13 04:35:35 DEBUG : dst/three.txt: md5 = 7986153b9af027f8dedf9f6db0e2ae25 OK 2025/02/13 04:35:35 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-cehowil2kivu/dst" 2025/02/13 04:35:36 DEBUG : Creating backend with remote "TestDrive:crypt/2taekpjjreop3k6cmt0r4mp4qbpg9lhqqk3ep1qfmvlh1ctr5r5g/31u3jie661vd5p8j7rtc3hgbh0" 2025/02/13 04:35:36 DEBUG : one: Sizes differ (src 4 vs dst 3) 2025/02/13 04:35:37 INFO : one: Moved (server-side) to: one.bak 2025/02/13 04:35:38 DEBUG : one: md5 = 25eae6075c1197a7a797787197b6f86d OK 2025/02/13 04:35:38 INFO : one: Copied (new) 2025/02/13 04:35:39 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/02/13 04:35:39 DEBUG : two: Unchanged skipping 2025/02/13 04:35:39 DEBUG : three.txt: Sizes differ (src 6 vs dst 5) 2025/02/13 04:35:40 INFO : three.txt: Moved (server-side) to: three.txt.bak 2025/02/13 04:35:41 DEBUG : three.txt: md5 = d7fee5095011ecaedfab12b15543b245 OK 2025/02/13 04:35:41 INFO : three.txt: Copied (new) 2025/02/13 04:35:43 DEBUG : one: Sizes differ (src 5 vs dst 4) 2025/02/13 04:35:43 INFO : one.bak: Deleted 2025/02/13 04:35:44 INFO : one: Moved (server-side) to: one.bak 2025/02/13 04:35:45 DEBUG : one: md5 = efa33ac01eb7df2d56746bad07a021b6 OK 2025/02/13 04:35:45 INFO : one: Copied (new) 2025/02/13 04:35:45 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/02/13 04:35:45 DEBUG : two: Unchanged skipping 2025/02/13 04:35:46 DEBUG : three.txt: Sizes differ (src 19 vs dst 6) 2025/02/13 04:35:46 INFO : three.txt.bak: Deleted 2025/02/13 04:35:47 INFO : three.txt: Moved (server-side) to: three.txt.bak 2025/02/13 04:35:48 DEBUG : three.txt: md5 = 5cce8930beab7be819b75d5871d3639c OK 2025/02/13 04:35:48 INFO : three.txt: Copied (new) 2025/02/13 04:35:51 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "tr2hj63d80ftlmvm6a952snjcc" 2025/02/13 04:35:51 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" 2025/02/13 04:35:51 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "qltcak2uaegtmcoa8vijdppbp8" 2025/02/13 04:35:51 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k" 2025/02/13 04:35:51 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "qltcak2uaegtmcoa8vijdppbp8" 2025/02/13 04:35:51 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "sk91qgsqfn0r271r2ehsaoc20c" 2025/02/13 04:35:51 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "sk91qgsqfn0r271r2ehsaoc20c" --- PASS: TestSyncSuffix (22.15s) === RUN TestSyncSuffixKeepExtension run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-cehowil2kivu'", Local "Local file system at /tmp/rclone251320568", Modify Window "1ms" 2025/02/13 04:35:54 DEBUG : dst/one: md5 = a30266d9369f0d326a0e9a074db66e6b OK 2025/02/13 04:35:56 DEBUG : dst/two: md5 = 395108237ef7516f65689fb1c82578c6 OK 2025/02/13 04:35:57 DEBUG : dst/three.txt: md5 = dc73160c941ce4bbf61735ee70be4518 OK 2025/02/13 04:35:58 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-cehowil2kivu/dst" 2025/02/13 04:35:58 DEBUG : Creating backend with remote "TestDrive:crypt/2taekpjjreop3k6cmt0r4mp4qbpg9lhqqk3ep1qfmvlh1ctr5r5g/31u3jie661vd5p8j7rtc3hgbh0" 2025/02/13 04:35:59 DEBUG : one: Sizes differ (src 4 vs dst 3) 2025/02/13 04:36:00 INFO : one: Moved (server-side) to: one-2019-01-01 2025/02/13 04:36:01 DEBUG : one: md5 = 30bf2b124db92c2651199f0e38f97a89 OK 2025/02/13 04:36:01 INFO : one: Copied (new) 2025/02/13 04:36:01 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/02/13 04:36:01 DEBUG : two: Unchanged skipping 2025/02/13 04:36:01 DEBUG : three.txt: Sizes differ (src 6 vs dst 5) 2025/02/13 04:36:02 INFO : three.txt: Moved (server-side) to: three-2019-01-01.txt 2025/02/13 04:36:04 DEBUG : three.txt: md5 = 38344b0870862bda649f9daf1f7c8811 OK 2025/02/13 04:36:04 INFO : three.txt: Copied (new) 2025/02/13 04:36:05 DEBUG : one: Sizes differ (src 5 vs dst 4) 2025/02/13 04:36:06 INFO : one-2019-01-01: Deleted 2025/02/13 04:36:06 INFO : one: Moved (server-side) to: one-2019-01-01 2025/02/13 04:36:08 DEBUG : one: md5 = 8aec3de0e2bc8119c1a2504a7718d913 OK 2025/02/13 04:36:08 INFO : one: Copied (new) 2025/02/13 04:36:08 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/02/13 04:36:08 DEBUG : two: Unchanged skipping 2025/02/13 04:36:08 DEBUG : three.txt: Sizes differ (src 19 vs dst 6) 2025/02/13 04:36:09 INFO : three-2019-01-01.txt: Deleted 2025/02/13 04:36:09 INFO : three.txt: Moved (server-side) to: three-2019-01-01.txt 2025/02/13 04:36:10 DEBUG : three.txt: md5 = a90423da3753d488be1b1bc2faa36f53 OK 2025/02/13 04:36:10 INFO : three.txt: Copied (new) 2025/02/13 04:36:14 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "tr2hj63d80ftlmvm6a952snjcc" 2025/02/13 04:36:14 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" 2025/02/13 04:36:14 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "jcjl1bv3ep0v8kt35lqql1co90" 2025/02/13 04:36:14 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "qtq2f6qq4lgpsmj88vb7147qje3prudmtfdtr2342fth58vo9a50" 2025/02/13 04:36:14 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "jcjl1bv3ep0v8kt35lqql1co90" 2025/02/13 04:36:14 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "qtq2f6qq4lgpsmj88vb7147qje3prudmtfdtr2342fth58vo9a50" 2025/02/13 04:36:14 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k" --- PASS: TestSyncSuffixKeepExtension (22.48s) === RUN TestSyncUTFNorm run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-cehowil2kivu'", Local "Local file system at /tmp/rclone251320568", Modify Window "1ms" 2025/02/13 04:36:16 DEBUG : Testêé: md5 = 2a1a40536f8d8e40a11573e12135596d OK 2025/02/13 04:36:16 DEBUG : Testêé: Sizes differ (src 14 vs dst 18) 2025/02/13 04:36:16 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-cehowil2kivu': Waiting for checks to finish 2025/02/13 04:36:16 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-cehowil2kivu': Waiting for transfers to finish 2025/02/13 04:36:18 DEBUG : Testêé: md5 = eff330514106f32ecab40af5631150b4 OK 2025/02/13 04:36:18 INFO : Testêé: Copied (replaced existing) to: Testêé 2025/02/13 04:36:18 DEBUG : Waiting for deletions to finish --- PASS: TestSyncUTFNorm (4.14s) === RUN TestSyncImmutable run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-cehowil2kivu'", Local "Local file system at /tmp/rclone251320568", Modify Window "1ms" 2025/02/13 04:36:19 DEBUG : existing: Need to transfer - File not found at Destination 2025/02/13 04:36:19 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-cehowil2kivu': Waiting for checks to finish 2025/02/13 04:36:19 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-cehowil2kivu': Waiting for transfers to finish 2025/02/13 04:36:21 DEBUG : existing: md5 = 083f314846768ae435d6488fa1b19464 OK 2025/02/13 04:36:21 INFO : existing: Copied (new) 2025/02/13 04:36:21 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-cehowil2kivu'", Local "Local file system at /tmp/rclone251320568", Modify Window "1ms" 2025/02/13 04:36:22 DEBUG : existing: Sizes differ (src 8 vs dst 6) 2025/02/13 04:36:22 ERROR : existing: Source and destination exist but do not match: immutable file modified 2025/02/13 04:36:22 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-cehowil2kivu': Waiting for checks to finish 2025/02/13 04:36:22 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-cehowil2kivu': Waiting for transfers to finish 2025/02/13 04:36:22 ERROR : Encrypted drive 'TestCryptDrive:rclone-test-cehowil2kivu': not deleting files as there were IO errors 2025/02/13 04:36:22 ERROR : Encrypted drive 'TestCryptDrive:rclone-test-cehowil2kivu': not deleting directories as there were IO errors run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-cehowil2kivu'", Local "Local file system at /tmp/rclone251320568", Modify Window "1ms" --- PASS: TestSyncImmutable (5.08s) === RUN TestSyncIgnoreCase run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-cehowil2kivu'", Local "Local file system at /tmp/rclone251320568", Modify Window "1ms" 2025/02/13 04:36:25 DEBUG : EXISTING: md5 = aceb4ec6e2ba7a217da3b6acb651c7b4 OK 2025/02/13 04:36:26 DEBUG : existing: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/02/13 04:36:26 DEBUG : existing: Unchanged skipping 2025/02/13 04:36:26 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-cehowil2kivu': Waiting for checks to finish 2025/02/13 04:36:26 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-cehowil2kivu': Waiting for transfers to finish 2025/02/13 04:36:26 DEBUG : Waiting for deletions to finish 2025/02/13 04:36:26 INFO : There was nothing to transfer --- PASS: TestSyncIgnoreCase (3.10s) === RUN TestFixCase run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-cehowil2kivu'", Local "Local file system at /tmp/rclone251320568", Modify Window "1ms" sync_test.go:2635: Skipping test as local or remote are case-sensitive --- SKIP: TestFixCase (0.43s) === RUN TestMaxTransfer === RUN TestMaxTransfer/Hard run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-cehowil2kivu'", Local "Local file system at /tmp/rclone251320568", 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-cehowil2kivu'", Local "Local file system at /tmp/rclone251320568", 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-cehowil2kivu'", Local "Local file system at /tmp/rclone251320568", Modify Window "1ms" sync_test.go:2674: This test only runs on local --- PASS: TestMaxTransfer (1.48s) --- SKIP: TestMaxTransfer/Hard (0.47s) --- SKIP: TestMaxTransfer/Soft (0.56s) --- SKIP: TestMaxTransfer/Cautious (0.45s) === RUN TestSyncConcurrentDelete run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-cehowil2kivu'", Local "Local file system at /tmp/rclone251320568", Modify Window "1ms" 2025/02/13 04:36:30 DEBUG : both0: md5 = 790b4e63e2d1210280c2c5c4f310d550 OK 2025/02/13 04:36:32 DEBUG : only0: md5 = 6baed1a4c16194fec8f332af39bcab42 OK 2025/02/13 04:36:33 DEBUG : both1: md5 = 5eee1344d54a34a12f8c0d90aa7939d9 OK 2025/02/13 04:36:34 DEBUG : only1: md5 = 0799a8cf43a78f827bdb0cdc5638f8c6 OK 2025/02/13 04:36:36 DEBUG : both2: md5 = 20694696461eebb7fd7f74c342c99054 OK 2025/02/13 04:36:37 DEBUG : only2: md5 = 0056788371f819ca4fee2e374df3a949 OK 2025/02/13 04:36:39 DEBUG : both3: md5 = 07799cb43edf72df2779f959e14db2f6 OK 2025/02/13 04:36:40 DEBUG : only3: md5 = a51162869f08b1680d22ca35733073f4 OK 2025/02/13 04:36:41 DEBUG : both4: md5 = f1aa5aedeb05be0f9ee40db400b67378 OK 2025/02/13 04:36:43 DEBUG : only4: md5 = 8116bf137224668f3a1012067cc4a0be OK 2025/02/13 04:36:44 DEBUG : both5: md5 = ece963917459bbb9c6b00c269594c7a9 OK 2025/02/13 04:36:46 DEBUG : only5: md5 = d5cb004ffe1cd08f3743e1100b297926 OK 2025/02/13 04:36:47 DEBUG : both6: md5 = 99652a040ff34b450914e51231ef3319 OK 2025/02/13 04:36:48 DEBUG : only6: md5 = 464312f81dc347b1f41552cbe1368faf OK 2025/02/13 04:36:49 DEBUG : both7: md5 = 8cf60122313ddaceb9f87ac4745199aa OK 2025/02/13 04:36:51 DEBUG : only7: md5 = 1ff38d04dea182e56a33e671f5917af1 OK 2025/02/13 04:36:52 DEBUG : both8: md5 = 8d5c56cd5f2c9e911a786c7f50e3f077 OK 2025/02/13 04:36:54 DEBUG : only8: md5 = 40604a9d7d3f21cc4cd9edfec828241d OK 2025/02/13 04:36:55 DEBUG : both9: md5 = 489321cb5a9382a350475bd931b00826 OK 2025/02/13 04:36:56 DEBUG : only9: md5 = 3308917d0a6ad3019c0440cb91a48deb OK 2025/02/13 04:36:58 DEBUG : both10: md5 = 954b81ca768d31e0b54015b66c80bf9a OK 2025/02/13 04:37:00 DEBUG : only10: md5 = 6f1156973be6a34a701072db0c09c3c8 OK 2025/02/13 04:37:01 DEBUG : both11: md5 = 5fb44af0b6f30836253fec191e4bc765 OK 2025/02/13 04:37:03 DEBUG : only11: md5 = 199e1008b2ec873edc3ede8f3364a1dd OK 2025/02/13 04:37:04 DEBUG : both12: md5 = 9faf78b7eaa81c78ca0083909a689985 OK 2025/02/13 04:37:06 DEBUG : only12: md5 = 3f73f020e7ba1f6e1ce46cb805ab4b26 OK 2025/02/13 04:37:07 DEBUG : both13: md5 = 01c3a90c435d721faf7311fa4acaa337 OK 2025/02/13 04:37:08 DEBUG : only13: md5 = 1fe3fa1d42c8749eaad2578d0990106c OK 2025/02/13 04:37:10 DEBUG : both14: md5 = d7f2b2ca5f0e7df9b5df13a59c78e33b OK 2025/02/13 04:37:11 DEBUG : only14: md5 = fb8876852c04984d25548d08dd251dd8 OK 2025/02/13 04:37:12 DEBUG : both15: md5 = acdb1ef9c348afa09b4d207528436399 OK 2025/02/13 04:37:14 DEBUG : only15: md5 = 06b952fa2f9459edeb4e033d531a300a OK 2025/02/13 04:37:15 DEBUG : both16: md5 = 59fc7bd606420de7600e34c975308662 OK 2025/02/13 04:37:17 DEBUG : only16: md5 = bfc43e0446daa301a16bcbdf881f3e00 OK 2025/02/13 04:37:18 DEBUG : both17: md5 = d9fcfe8b54399819ec91cd734751626a OK 2025/02/13 04:37:19 DEBUG : only17: md5 = b0fbe7238d6fd576efbee91aa1ffa697 OK 2025/02/13 04:37:21 DEBUG : both18: md5 = 76827b07304b499dbfdc9fb6d3df4424 OK 2025/02/13 04:37:22 DEBUG : only18: md5 = c537b872526a5f27ea594eed8f0affaf OK 2025/02/13 04:37:23 DEBUG : both19: md5 = 57b9014fa829fd291f1a4df8bbeb4857 OK 2025/02/13 04:37:24 DEBUG : only19: md5 = 157418d543a27fc8caf2d0527b7cc0b0 OK 2025/02/13 04:37:25 DEBUG : both0: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/02/13 04:37:25 DEBUG : both10: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/02/13 04:37:25 DEBUG : both1: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/02/13 04:37:25 DEBUG : both11: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/02/13 04:37:25 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-cehowil2kivu': Waiting for checks to finish 2025/02/13 04:37:25 DEBUG : both0: Unchanged skipping 2025/02/13 04:37:25 DEBUG : both12: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/02/13 04:37:25 DEBUG : both12: Unchanged skipping 2025/02/13 04:37:25 DEBUG : both13: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/02/13 04:37:25 DEBUG : both13: Unchanged skipping 2025/02/13 04:37:25 DEBUG : both14: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/02/13 04:37:25 DEBUG : both10: Unchanged skipping 2025/02/13 04:37:25 DEBUG : both15: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/02/13 04:37:25 DEBUG : both1: Unchanged skipping 2025/02/13 04:37:25 DEBUG : both16: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/02/13 04:37:25 DEBUG : both11: Unchanged skipping 2025/02/13 04:37:25 DEBUG : both17: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/02/13 04:37:25 DEBUG : both17: Unchanged skipping 2025/02/13 04:37:25 DEBUG : both18: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/02/13 04:37:25 DEBUG : both14: Unchanged skipping 2025/02/13 04:37:25 DEBUG : both19: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/02/13 04:37:25 DEBUG : both19: Unchanged skipping 2025/02/13 04:37:25 DEBUG : both2: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/02/13 04:37:25 DEBUG : both2: Unchanged skipping 2025/02/13 04:37:25 DEBUG : both3: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/02/13 04:37:25 DEBUG : both3: Unchanged skipping 2025/02/13 04:37:25 DEBUG : both4: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/02/13 04:37:25 DEBUG : both4: Unchanged skipping 2025/02/13 04:37:25 DEBUG : both5: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/02/13 04:37:25 DEBUG : both5: Unchanged skipping 2025/02/13 04:37:25 DEBUG : both6: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/02/13 04:37:25 DEBUG : both6: Unchanged skipping 2025/02/13 04:37:25 DEBUG : both7: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/02/13 04:37:25 DEBUG : both7: Unchanged skipping 2025/02/13 04:37:25 DEBUG : both8: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/02/13 04:37:25 DEBUG : both8: Unchanged skipping 2025/02/13 04:37:25 DEBUG : both9: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/02/13 04:37:25 DEBUG : both15: Unchanged skipping 2025/02/13 04:37:25 DEBUG : both16: Unchanged skipping 2025/02/13 04:37:25 DEBUG : both18: Unchanged skipping 2025/02/13 04:37:25 DEBUG : both9: Unchanged skipping 2025/02/13 04:37:25 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-cehowil2kivu': Waiting for transfers to finish 2025/02/13 04:37:25 DEBUG : Waiting for deletions to finish 2025/02/13 04:37:25 INFO : only8: Deleted 2025/02/13 04:37:25 INFO : only4: Deleted 2025/02/13 04:37:25 INFO : only19: Deleted 2025/02/13 04:37:25 INFO : only1: Deleted 2025/02/13 04:37:26 INFO : only13: Deleted 2025/02/13 04:37:26 INFO : only14: Deleted 2025/02/13 04:37:26 INFO : only17: Deleted 2025/02/13 04:37:26 INFO : only15: Deleted 2025/02/13 04:37:26 INFO : only18: Deleted 2025/02/13 04:37:26 INFO : only7: Deleted 2025/02/13 04:37:26 INFO : only9: Deleted 2025/02/13 04:37:26 INFO : only0: Deleted 2025/02/13 04:37:27 INFO : only10: Deleted 2025/02/13 04:37:27 INFO : only2: Deleted 2025/02/13 04:37:27 INFO : only16: Deleted 2025/02/13 04:37:27 INFO : only3: Deleted 2025/02/13 04:37:27 INFO : only5: Deleted 2025/02/13 04:37:27 INFO : only12: Deleted 2025/02/13 04:37:27 INFO : only6: Deleted 2025/02/13 04:37:27 INFO : only11: Deleted 2025/02/13 04:37:27 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-cehowil2kivu'", Local "Local file system at /tmp/rclone251320568", Modify Window "1ms" --- PASS: TestSyncConcurrentDelete (68.87s) === RUN TestSyncConcurrentTruncate run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-cehowil2kivu'", Local "Local file system at /tmp/rclone251320568", Modify Window "1ms" 2025/02/13 04:37:39 DEBUG : both0: md5 = 52b9b2071b5004b0788d2eefd8b180d9 OK 2025/02/13 04:37:41 DEBUG : only0: md5 = bc42584f7043e3b82e5164243fd3530b OK 2025/02/13 04:37:42 DEBUG : both1: md5 = fe00d36d278cbd7fe46a3e9fb0890426 OK 2025/02/13 04:37:43 DEBUG : only1: md5 = 7f5d8d8b381b152e254b6f03e0b9ced5 OK 2025/02/13 04:37:45 DEBUG : both2: md5 = f6ed9b466634f332e9fdccd2be2e6455 OK 2025/02/13 04:37:46 DEBUG : only2: md5 = 04be75560add95fea802c287ba1668ca OK 2025/02/13 04:37:47 DEBUG : both3: md5 = b906db520df163e1493a551148d39b7f OK 2025/02/13 04:37:49 DEBUG : only3: md5 = 6ba3373380925b9af1f45d8e5d311197 OK 2025/02/13 04:37:50 DEBUG : both4: md5 = 6c6612690a438291fe359bd6a2268a24 OK 2025/02/13 04:37:51 DEBUG : only4: md5 = 02953320e76e744e4741792f791a14ad OK 2025/02/13 04:37:53 DEBUG : both5: md5 = a589982134527186f7136d81579ffec9 OK 2025/02/13 04:37:54 DEBUG : only5: md5 = 0343a15f19b967c46dac2b1229a1cb99 OK 2025/02/13 04:37:56 DEBUG : both6: md5 = 4170766d048bd045b5fdbdce5f01af7d OK 2025/02/13 04:37:57 DEBUG : only6: md5 = 240c3a1a311f5c807e9fd4ac41bbf636 OK 2025/02/13 04:37:58 DEBUG : both7: md5 = 2a1655f393a06c5f664d7fa6ca23cba9 OK 2025/02/13 04:38:00 DEBUG : only7: md5 = 582a6c26a418c9540c91c59ed66ea5ff OK 2025/02/13 04:38:01 DEBUG : both8: md5 = 7d97c393967cd2c326e930688a4a1113 OK 2025/02/13 04:38:03 DEBUG : only8: md5 = c48d7a7c8fc96f8ef15f36440de63382 OK 2025/02/13 04:38:04 DEBUG : both9: md5 = d56a44561b1c70f445b8eae481bd85cd OK 2025/02/13 04:38:05 DEBUG : only9: md5 = 1ed4360cab509d5781a50ca6d6c82ea0 OK 2025/02/13 04:38:06 DEBUG : both10: md5 = 8eeaba77f2fc8905e789f3786a00bd1a OK 2025/02/13 04:38:08 DEBUG : only10: md5 = c1f35b6a5bec6a541b5fdfd131079aa3 OK 2025/02/13 04:38:09 DEBUG : both11: md5 = 97f3629d5c5e9629f7eee61a221b5998 OK 2025/02/13 04:38:11 DEBUG : only11: md5 = 4f5d84a5a2a55cc621ac614be53d9a56 OK 2025/02/13 04:38:12 DEBUG : both12: md5 = 2c7f3408bdb814a3cbb604b3f29abef8 OK 2025/02/13 04:38:14 DEBUG : only12: md5 = 625d74f025897a79504e97ded7ee1e6d OK 2025/02/13 04:38:15 DEBUG : both13: md5 = 80aac2da4a641908b6514547243bccdb OK 2025/02/13 04:38:16 DEBUG : only13: md5 = 8cd23026a22e7dd959b180b7778b2884 OK 2025/02/13 04:38:18 DEBUG : both14: md5 = bdb239dc035a7a8d86d2b3c7efe8f265 OK 2025/02/13 04:38:19 DEBUG : only14: md5 = f493472bbe7dced155dac2440443bfe5 OK 2025/02/13 04:38:21 DEBUG : both15: md5 = d9ede4f98fbcf4332332c86d6075a737 OK 2025/02/13 04:38:22 DEBUG : only15: md5 = 6169b9f827bf53adc2f6e9fda69cb294 OK 2025/02/13 04:38:24 DEBUG : both16: md5 = 61247e51d5d80d980299e154c24b22e6 OK 2025/02/13 04:38:25 DEBUG : only16: md5 = 03072115538556ed150be85178cde747 OK 2025/02/13 04:38:26 DEBUG : both17: md5 = 100bc8f851b6d7a9059eb00b7bfac65b OK 2025/02/13 04:38:28 DEBUG : only17: md5 = a92b1ee2ce35fec0f3bdf24d6ced33a6 OK 2025/02/13 04:38:29 DEBUG : both18: md5 = c09288a43d79268e419cc67a97913bf8 OK 2025/02/13 04:38:30 DEBUG : only18: md5 = f7b192fd7ddd4443ffebcabeedeb61fa OK 2025/02/13 04:38:32 DEBUG : both19: md5 = b35b3026b3bcaacdc81e2bcc1cb31897 OK 2025/02/13 04:38:33 DEBUG : only19: md5 = 3181bc814068532116eebb4d1afe3758 OK 2025/02/13 04:38:34 DEBUG : both0: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/02/13 04:38:34 DEBUG : both1: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/02/13 04:38:34 DEBUG : both10: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/02/13 04:38:34 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-cehowil2kivu': Waiting for checks to finish 2025/02/13 04:38:34 DEBUG : both0: Unchanged skipping 2025/02/13 04:38:34 DEBUG : both11: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/02/13 04:38:34 DEBUG : both12: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/02/13 04:38:34 DEBUG : both1: Unchanged skipping 2025/02/13 04:38:34 DEBUG : both13: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/02/13 04:38:34 DEBUG : both13: Unchanged skipping 2025/02/13 04:38:34 DEBUG : both14: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/02/13 04:38:34 DEBUG : both14: Unchanged skipping 2025/02/13 04:38:34 DEBUG : both15: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/02/13 04:38:34 DEBUG : both10: Unchanged skipping 2025/02/13 04:38:34 DEBUG : both16: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/02/13 04:38:34 DEBUG : both16: Unchanged skipping 2025/02/13 04:38:34 DEBUG : both17: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/02/13 04:38:34 DEBUG : both17: Unchanged skipping 2025/02/13 04:38:34 DEBUG : both18: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/02/13 04:38:34 DEBUG : both18: Unchanged skipping 2025/02/13 04:38:34 DEBUG : both19: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/02/13 04:38:34 DEBUG : both11: Unchanged skipping 2025/02/13 04:38:34 DEBUG : both2: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/02/13 04:38:34 DEBUG : both2: Unchanged skipping 2025/02/13 04:38:34 DEBUG : both3: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/02/13 04:38:34 DEBUG : both12: Unchanged skipping 2025/02/13 04:38:34 DEBUG : both4: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/02/13 04:38:34 DEBUG : both4: Unchanged skipping 2025/02/13 04:38:34 DEBUG : both5: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/02/13 04:38:34 DEBUG : both5: Unchanged skipping 2025/02/13 04:38:34 DEBUG : both6: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/02/13 04:38:34 DEBUG : both6: Unchanged skipping 2025/02/13 04:38:34 DEBUG : both7: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/02/13 04:38:34 DEBUG : both7: Unchanged skipping 2025/02/13 04:38:34 DEBUG : both8: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/02/13 04:38:34 DEBUG : both8: Unchanged skipping 2025/02/13 04:38:34 DEBUG : both9: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/02/13 04:38:34 DEBUG : both9: Unchanged skipping 2025/02/13 04:38:34 DEBUG : only0: Sizes differ (src 0 vs dst 6) 2025/02/13 04:38:34 DEBUG : only1: Sizes differ (src 0 vs dst 6) 2025/02/13 04:38:34 DEBUG : both15: Unchanged skipping 2025/02/13 04:38:34 DEBUG : only10: Sizes differ (src 0 vs dst 6) 2025/02/13 04:38:34 DEBUG : both19: Unchanged skipping 2025/02/13 04:38:34 DEBUG : only11: Sizes differ (src 0 vs dst 6) 2025/02/13 04:38:34 DEBUG : only12: Sizes differ (src 0 vs dst 6) 2025/02/13 04:38:34 DEBUG : both3: Unchanged skipping 2025/02/13 04:38:34 DEBUG : only13: Sizes differ (src 0 vs dst 6) 2025/02/13 04:38:34 DEBUG : only14: Sizes differ (src 0 vs dst 6) 2025/02/13 04:38:34 DEBUG : only15: Sizes differ (src 0 vs dst 6) 2025/02/13 04:38:34 DEBUG : only16: Sizes differ (src 0 vs dst 6) 2025/02/13 04:38:34 DEBUG : only17: Sizes differ (src 0 vs dst 6) 2025/02/13 04:38:34 DEBUG : only18: Sizes differ (src 0 vs dst 6) 2025/02/13 04:38:34 DEBUG : only19: Sizes differ (src 0 vs dst 6) 2025/02/13 04:38:34 DEBUG : only2: Sizes differ (src 0 vs dst 6) 2025/02/13 04:38:34 DEBUG : only3: Sizes differ (src 0 vs dst 6) 2025/02/13 04:38:34 DEBUG : only4: Sizes differ (src 0 vs dst 6) 2025/02/13 04:38:34 DEBUG : only5: Sizes differ (src 0 vs dst 6) 2025/02/13 04:38:34 DEBUG : only6: Sizes differ (src 0 vs dst 6) 2025/02/13 04:38:34 DEBUG : only7: Sizes differ (src 0 vs dst 6) 2025/02/13 04:38:34 DEBUG : only8: Sizes differ (src 0 vs dst 6) 2025/02/13 04:38:34 DEBUG : only9: Sizes differ (src 0 vs dst 6) 2025/02/13 04:38:34 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-cehowil2kivu': Waiting for transfers to finish 2025/02/13 04:38:35 DEBUG : only11: md5 = 9586cf1332ddb879a562e91695d972fb OK 2025/02/13 04:38:35 INFO : only11: Copied (replaced existing) 2025/02/13 04:38:35 DEBUG : only13: md5 = ae7d54f6c269001ea65f296d253eabf2 OK 2025/02/13 04:38:35 INFO : only13: Copied (replaced existing) 2025/02/13 04:38:35 DEBUG : only14: md5 = df567b6224e663599d8b51a339a3d8e6 OK 2025/02/13 04:38:35 INFO : only14: Copied (replaced existing) 2025/02/13 04:38:35 DEBUG : only0: md5 = 45d37624263f1f0004f2cf2209f75681 OK 2025/02/13 04:38:35 INFO : only0: Copied (replaced existing) 2025/02/13 04:38:36 DEBUG : only16: md5 = d2bc0f4d22b411d8854eb079e50ead5f OK 2025/02/13 04:38:36 INFO : only16: Copied (replaced existing) 2025/02/13 04:38:36 DEBUG : only17: md5 = da7d1f0adb2e3102f7ebbae2bc2c3f10 OK 2025/02/13 04:38:36 INFO : only17: Copied (replaced existing) 2025/02/13 04:38:36 DEBUG : only15: md5 = 4558998c09d2675c15561315db7b6126 OK 2025/02/13 04:38:36 INFO : only15: Copied (replaced existing) 2025/02/13 04:38:36 DEBUG : only18: md5 = 4fd7959370b6c19054849e8d81f0e8e1 OK 2025/02/13 04:38:36 INFO : only18: Copied (replaced existing) 2025/02/13 04:38:37 DEBUG : only19: md5 = bf9e0b63f5c359a1cb6044c125505068 OK 2025/02/13 04:38:37 INFO : only19: Copied (replaced existing) 2025/02/13 04:38:37 DEBUG : only3: md5 = 3716923cd5b263cf3ace9f58cc80b391 OK 2025/02/13 04:38:37 INFO : only3: Copied (replaced existing) 2025/02/13 04:38:37 DEBUG : only2: md5 = ac39b4c83b575e73e42290affc52d68f OK 2025/02/13 04:38:37 INFO : only2: Copied (replaced existing) 2025/02/13 04:38:38 DEBUG : only4: md5 = 0c8b8e285ce739c9928e46b526be1437 OK 2025/02/13 04:38:38 INFO : only4: Copied (replaced existing) 2025/02/13 04:38:38 DEBUG : only1: md5 = a6d7bb31ed30d42eb43e77d575a85f2e OK 2025/02/13 04:38:38 INFO : only1: Copied (replaced existing) 2025/02/13 04:38:38 DEBUG : only5: md5 = 5e33722621a620fd2037d0aabef65de1 OK 2025/02/13 04:38:38 INFO : only5: Copied (replaced existing) 2025/02/13 04:38:38 DEBUG : only6: md5 = 0d23f865bc8404b56c15cd25249053b1 OK 2025/02/13 04:38:38 INFO : only6: Copied (replaced existing) 2025/02/13 04:38:39 DEBUG : only10: md5 = 9a270ff7f0fc5bc8b689a437134f13e4 OK 2025/02/13 04:38:39 INFO : only10: Copied (replaced existing) 2025/02/13 04:38:39 DEBUG : only7: md5 = e1d2ce86393caa1a23f1af1296af2f39 OK 2025/02/13 04:38:39 INFO : only7: Copied (replaced existing) 2025/02/13 04:38:39 DEBUG : only8: md5 = 5694c41ef80fa52ee8fdb589e2eddc4f OK 2025/02/13 04:38:39 INFO : only8: Copied (replaced existing) 2025/02/13 04:38:39 DEBUG : only12: md5 = b360d9b4155c000ec2ee78791aae1fa7 OK 2025/02/13 04:38:39 INFO : only12: Copied (replaced existing) 2025/02/13 04:38:40 DEBUG : only9: md5 = d5fac07795e7994e446a693a83ea6036 OK 2025/02/13 04:38:40 INFO : only9: Copied (replaced existing) 2025/02/13 04:38:40 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-cehowil2kivu'", Local "Local file system at /tmp/rclone251320568", Modify Window "1ms" --- PASS: TestSyncConcurrentTruncate (80.88s) === RUN TestSyncReplaceDirModTime run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-cehowil2kivu'", Local "Local file system at /tmp/rclone251320568", Modify Window "1ms" 2025/02/13 04:38:59 DEBUG : empty_dir: Making directory with metadata 2025/02/13 04:38:59 INFO : empty_dir: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2025/02/13 04:38:59 DEBUG : empty_on_remote: Making directory with metadata 2025/02/13 04:38:59 INFO : empty_on_remote: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2025/02/13 04:38:59 DEBUG : empty_on_remote: Making directory with metadata 2025/02/13 04:38:59 INFO : empty_on_remote: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-cehowil2kivu'", Local "Local file system at /tmp/rclone251320568", Modify Window "1ms" 2025/02/13 04:39:05 INFO : test_dir1: Set directory modification time (using DirSetModTime) 2025/02/13 04:39:05 INFO : test_dir2: Set directory modification time (using DirSetModTime) 2025/02/13 04:39:05 INFO : test_dir2/sub_dir: Set directory modification time (using DirSetModTime) 2025/02/13 04:39:05 INFO : empty_on_remote: Set directory modification time (using DirSetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-cehowil2kivu'", Local "Local file system at /tmp/rclone251320568", Modify Window "1ms" 2025/02/13 04:39:12 DEBUG : heqj02jg0dcqlem7gl0500bvp0/24g2k8bseitblkmqnie1ibl2s8: Rmdir: contains trashed file: "633fmaa0qic3kv3cladnu11pto" 2025/02/13 04:39:13 DEBUG : heqj02jg0dcqlem7gl0500bvp0: Rmdir: contains trashed file: "24g2k8bseitblkmqnie1ibl2s8" 2025/02/13 04:39:14 DEBUG : gq68srrpl0nnf394bgf7dbu9kc: Rmdir: contains trashed file: "d26uovf0miqhd1mu3c9jbseq00" --- PASS: TestSyncReplaceDirModTime (17.44s) === RUN TestSyncReplaceDirModTimeWithEmptyDirs run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-cehowil2kivu'", Local "Local file system at /tmp/rclone251320568", Modify Window "1ms" 2025/02/13 04:39:16 DEBUG : empty_dir: Making directory with metadata 2025/02/13 04:39:16 INFO : empty_dir: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2025/02/13 04:39:16 DEBUG : empty_on_remote: Making directory with metadata 2025/02/13 04:39:16 INFO : empty_on_remote: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2025/02/13 04:39:16 DEBUG : empty_on_remote: Making directory with metadata 2025/02/13 04:39:17 INFO : empty_on_remote: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-cehowil2kivu'", Local "Local file system at /tmp/rclone251320568", Modify Window "1ms" 2025/02/13 04:39:21 INFO : test_dir1: Set directory modification time (using DirSetModTime) 2025/02/13 04:39:21 INFO : test_dir2: Set directory modification time (using DirSetModTime) 2025/02/13 04:39:21 INFO : test_dir2/sub_dir: Set directory modification time (using DirSetModTime) 2025/02/13 04:39:21 INFO : empty_on_remote: Set directory modification time (using DirSetModTime) 2025/02/13 04:39:21 INFO : empty_dir: Set directory modification time (using DirSetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-cehowil2kivu'", Local "Local file system at /tmp/rclone251320568", Modify Window "1ms" 2025/02/13 04:39:29 DEBUG : heqj02jg0dcqlem7gl0500bvp0/24g2k8bseitblkmqnie1ibl2s8: Rmdir: contains trashed file: "633fmaa0qic3kv3cladnu11pto" 2025/02/13 04:39:30 DEBUG : heqj02jg0dcqlem7gl0500bvp0: Rmdir: contains trashed file: "24g2k8bseitblkmqnie1ibl2s8" 2025/02/13 04:39:30 DEBUG : gq68srrpl0nnf394bgf7dbu9kc: Rmdir: contains trashed file: "d26uovf0miqhd1mu3c9jbseq00" --- PASS: TestSyncReplaceDirModTimeWithEmptyDirs (17.23s) === RUN TestNothingToTransferWithEmptyDirs run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-cehowil2kivu'", Local "Local file system at /tmp/rclone251320568", Modify Window "1ms" 2025/02/13 04:39:33 INFO : sub dir: Set directory modification time (using DirSetModTime) 2025/02/13 04:39:33 DEBUG : sub dir: Making directory with metadata 2025/02/13 04:39:34 INFO : sub dir: Made directory with metadata (mtime=2011-12-30T12:59:59Z) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-cehowil2kivu'", Local "Local file system at /tmp/rclone251320568", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-cehowil2kivu'", Local "Local file system at /tmp/rclone251320568", Modify Window "1ms" 2025/02/13 04:39:52 INFO : sub dir2: Set directory modification time (using DirSetModTime) 2025/02/13 04:39:53 INFO : sub dir2: Set directory modification time (using DirSetModTime) 2025/02/13 04:39:53 INFO : sub dirEmpty/sub dirEmpty2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2025/02/13 04:39:53 INFO : sub dirEmpty: Set directory modification time (using DirSetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-cehowil2kivu'", Local "Local file system at /tmp/rclone251320568", Modify Window "1ms" 2025/02/13 04:40:05 DEBUG : gcsdkq814sbtppue42dpsbg8ug: Rmdir: contains trashed file: "sjuo65gk5q3r1199jselk9k9o0" 2025/02/13 04:40:06 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/37qp6d1gohacv723ij3brofbu8/i24n0ln37pa2hv8pctddeuh73o: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" 2025/02/13 04:40:07 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/37qp6d1gohacv723ij3brofbu8: Rmdir: contains trashed file: "i24n0ln37pa2hv8pctddeuh73o" 2025/02/13 04:40:07 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "37qp6d1gohacv723ij3brofbu8" 2025/02/13 04:40:08 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak" 2025/02/13 04:40:09 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak" 2025/02/13 04:40:09 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak" 2025/02/13 04:40:10 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak" 2025/02/13 04:40:11 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/4r13oncfa2rsrr82oqhsqv24ns: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" 2025/02/13 04:40:11 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc: Rmdir: contains trashed file: "4r13oncfa2rsrr82oqhsqv24ns" 2025/02/13 04:40:11 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak" 2025/02/13 04:40:12 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestNothingToTransferWithEmptyDirs (41.20s) === RUN TestNothingToTransferWithoutEmptyDirs run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-cehowil2kivu'", Local "Local file system at /tmp/rclone251320568", Modify Window "1ms" 2025/02/13 04:40:15 INFO : sub dir: Set directory modification time (using DirSetModTime) 2025/02/13 04:40:15 DEBUG : sub dir: Making directory with metadata 2025/02/13 04:40:15 INFO : sub dir: Made directory with metadata (mtime=2011-12-30T12:59:59Z) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-cehowil2kivu'", Local "Local file system at /tmp/rclone251320568", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-cehowil2kivu'", Local "Local file system at /tmp/rclone251320568", Modify Window "1ms" 2025/02/13 04:40:37 INFO : sub dir2: Set directory modification time (using DirSetModTime) 2025/02/13 04:40:38 INFO : sub dir2: Set directory modification time (using DirSetModTime) 2025/02/13 04:40:38 INFO : sub dirEmpty/sub dirEmpty2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2025/02/13 04:40:38 INFO : sub dirEmpty: Set directory modification time (using DirSetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-cehowil2kivu'", Local "Local file system at /tmp/rclone251320568", Modify Window "1ms" 2025/02/13 04:40:49 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/37qp6d1gohacv723ij3brofbu8/i24n0ln37pa2hv8pctddeuh73o: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" 2025/02/13 04:40:50 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/37qp6d1gohacv723ij3brofbu8: Rmdir: contains trashed file: "i24n0ln37pa2hv8pctddeuh73o" 2025/02/13 04:40:51 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "37qp6d1gohacv723ij3brofbu8" 2025/02/13 04:40:51 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak" 2025/02/13 04:40:52 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak" 2025/02/13 04:40:53 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak" 2025/02/13 04:40:54 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak" 2025/02/13 04:40:54 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/4r13oncfa2rsrr82oqhsqv24ns: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" 2025/02/13 04:40:55 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc: Rmdir: contains trashed file: "4r13oncfa2rsrr82oqhsqv24ns" 2025/02/13 04:40:55 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak" 2025/02/13 04:40:56 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestNothingToTransferWithoutEmptyDirs (43.23s) PASS 2025/02/13 04:40:58 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-cehowil2kivu': Purge remote "./sync.test -test.v -test.timeout 1h0m0s -remote TestCryptDrive: -verbose" - Finished OK in 15m57.238189577s (try 1/5)