"./sync.test -test.v -test.timeout 1h0m0s -remote TestCryptDrive: -verbose" - Starting (try 1/5) 2025/03/07 11:12:35 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-filesez1jaqi" 2025/03/07 11:12:35 DEBUG : Using config file from "/home/rclone/.rclone.conf" 2025/03/07 11:12:35 DEBUG : Creating backend with remote "TestDrive:crypt/ippqhs6o8n8f9aihb4n2s696sijniukgi2cvh83jmt0ape415uj0" 2025/03/07 11:12:35 DEBUG : TestDrive: Loaded invalid token from config file - ignoring 2025/03/07 11:12:35 DEBUG : Saving config "token" in section "TestDrive" of the config file 2025/03/07 11:12:35 DEBUG : TestDrive: Saved new token in config file 2025/03/07 11:12:36 DEBUG : Creating backend with remote "/tmp/rclone2831462366" === RUN TestPipe --- PASS: TestPipe (0.00s) === RUN TestPipeConcurrent --- PASS: TestPipeConcurrent (0.03s) === RUN TestPipeOrderBy === RUN TestPipeOrderBy/#00 === RUN TestPipeOrderBy/size === RUN TestPipeOrderBy/name === RUN TestPipeOrderBy/modtime === RUN TestPipeOrderBy/size,ascending === RUN TestPipeOrderBy/name,asc === RUN TestPipeOrderBy/modtime,ascending === RUN TestPipeOrderBy/size,descending === RUN TestPipeOrderBy/name,desc === RUN TestPipeOrderBy/modtime,descending === RUN TestPipeOrderBy/size,mixed,50 === RUN TestPipeOrderBy/size,mixed,51 --- PASS: TestPipeOrderBy (0.00s) --- PASS: TestPipeOrderBy/#00 (0.00s) --- PASS: TestPipeOrderBy/size (0.00s) --- PASS: TestPipeOrderBy/name (0.00s) --- PASS: TestPipeOrderBy/modtime (0.00s) --- PASS: TestPipeOrderBy/size,ascending (0.00s) --- PASS: TestPipeOrderBy/name,asc (0.00s) --- PASS: TestPipeOrderBy/modtime,ascending (0.00s) --- PASS: TestPipeOrderBy/size,descending (0.00s) --- PASS: TestPipeOrderBy/name,desc (0.00s) --- PASS: TestPipeOrderBy/modtime,descending (0.00s) --- PASS: TestPipeOrderBy/size,mixed,50 (0.00s) --- PASS: TestPipeOrderBy/size,mixed,51 (0.00s) === RUN TestNewLess === RUN TestNewLess/blankOK === RUN TestNewLess/tooManyParts === RUN TestNewLess/tooManyParts2 === RUN TestNewLess/badMixed === RUN TestNewLess/unknownComparison === RUN TestNewLess/unknownSortDirection === RUN TestNewLess/size === RUN TestNewLess/name === RUN TestNewLess/modtime === RUN TestNewLess/size,ascending === RUN TestNewLess/name,asc === RUN TestNewLess/modtime,ascending === RUN TestNewLess/size,descending === RUN TestNewLess/name,desc === RUN TestNewLess/modtime,descending === RUN TestNewLess/modtime,mixed === RUN TestNewLess/modtime,mixed,30 --- PASS: TestNewLess (0.00s) --- PASS: TestNewLess/blankOK (0.00s) --- PASS: TestNewLess/tooManyParts (0.00s) --- PASS: TestNewLess/tooManyParts2 (0.00s) --- PASS: TestNewLess/badMixed (0.00s) --- PASS: TestNewLess/unknownComparison (0.00s) --- PASS: TestNewLess/unknownSortDirection (0.00s) --- PASS: TestNewLess/size (0.00s) --- PASS: TestNewLess/name (0.00s) --- PASS: TestNewLess/modtime (0.00s) --- PASS: TestNewLess/size,ascending (0.00s) --- PASS: TestNewLess/name,asc (0.00s) --- PASS: TestNewLess/modtime,ascending (0.00s) --- PASS: TestNewLess/size,descending (0.00s) --- PASS: TestNewLess/name,desc (0.00s) --- PASS: TestNewLess/modtime,descending (0.00s) --- PASS: TestNewLess/modtime,mixed (0.00s) --- PASS: TestNewLess/modtime,mixed,30 (0.00s) === RUN TestRcCopy rc_test.go:16: Skipping test on non local remote --- SKIP: TestRcCopy (0.00s) === RUN TestRcMove rc_test.go:16: Skipping test on non local remote --- SKIP: TestRcMove (0.00s) === RUN TestRcSync rc_test.go:16: Skipping test on non local remote --- SKIP: TestRcSync (0.00s) === RUN TestCopyWithDryRun run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-filesez1jaqi'", Local "Local file system at /tmp/rclone2831462366", Modify Window "1ms" 2025/03/07 11:12:37 DEBUG : Added delayed dir = "sub dir", newDst= 2025/03/07 11:12:37 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2025/03/07 11:12:37 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-filesez1jaqi': Waiting for checks to finish 2025/03/07 11:12:37 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-filesez1jaqi': Waiting for transfers to finish 2025/03/07 11:12:37 NOTICE: sub dir/hello world: Skipped copy as --dry-run is set (size 11) 2025/03/07 11:12:37 NOTICE: sub dir: Skipped set directory modification time as --dry-run is set run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-filesez1jaqi'", Local "Local file system at /tmp/rclone2831462366", Modify Window "1ms" --- PASS: TestCopyWithDryRun (2.33s) === RUN TestCopy run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-filesez1jaqi'", Local "Local file system at /tmp/rclone2831462366", Modify Window "1ms" 2025/03/07 11:12:39 INFO : sub dir: Set directory modification time (using DirSetModTime) 2025/03/07 11:12:39 DEBUG : Added delayed dir = "sub dir", newDst= 2025/03/07 11:12:39 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2025/03/07 11:12:39 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-filesez1jaqi': Waiting for checks to finish 2025/03/07 11:12:39 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-filesez1jaqi': Waiting for transfers to finish 2025/03/07 11:12:41 DEBUG : sub dir/hello world: md5 = a0f886e793f0ee364443d58ff886057d OK 2025/03/07 11:12:41 INFO : sub dir/hello world: Copied (new) 2025/03/07 11:12:42 INFO : sub dir: Set directory modification time (using DirSetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-filesez1jaqi'", Local "Local file system at /tmp/rclone2831462366", Modify Window "1ms" 2025/03/07 11:12:44 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestCopy (6.49s) === RUN TestCopyMetadata run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-filesez1jaqi'", Local "Local file system at /tmp/rclone2831462366", Modify Window "1ms" 2025/03/07 11:12:45 DEBUG : metadata sub dir: Making directory with metadata 2025/03/07 11:12:45 INFO : metadata sub dir: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2025/03/07 11:12:45 DEBUG : empty metadata sub dir: Making directory with metadata 2025/03/07 11:12:45 INFO : empty metadata sub dir: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2025/03/07 11:12:45 DEBUG : Local file system at /tmp/rclone2831462366: File to upload is small (21 bytes), uploading instead of streaming 2025/03/07 11:12:45 DEBUG : metadata sub dir/hello metadata world: md5 = baa7a013449dbba2b1ed02b5cfb4e1a2 OK 2025/03/07 11:12:45 DEBUG : metadata sub dir/hello metadata world: Size and md5 of src and dst objects identical 2025/03/07 11:12:45 INFO : metadata sub dir: Set directory modification time (using DirSetModTime) 2025/03/07 11:12:46 DEBUG : Google drive root 'crypt/ippqhs6o8n8f9aihb4n2s696sijniukgi2cvh83jmt0ape415uj0': Skipping btime metadata as can't update it on an existing file: 2025-03-07T11:12:45.52259755Z 2025/03/07 11:12:46 INFO : empty metadata sub dir: Updated directory metadata 2025/03/07 11:12:46 DEBUG : Google drive root 'crypt/ippqhs6o8n8f9aihb4n2s696sijniukgi2cvh83jmt0ape415uj0': Skipping btime metadata as can't update it on an existing file: 2025-03-07T11:12:45.52259755Z 2025/03/07 11:12:47 INFO : metadata sub dir: Updated directory metadata 2025/03/07 11:12:47 DEBUG : metadata sub dir/hello metadata world: Need to transfer - File not found at Destination 2025/03/07 11:12:47 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-filesez1jaqi': Waiting for checks to finish 2025/03/07 11:12:47 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-filesez1jaqi': Waiting for transfers to finish 2025/03/07 11:12:48 DEBUG : metadata sub dir/hello metadata world: md5 = 65bc2e722bc02d7ce83593e5f481d5eb OK 2025/03/07 11:12:48 INFO : metadata sub dir/hello metadata world: Copied (new) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-filesez1jaqi'", Local "Local file system at /tmp/rclone2831462366", Modify Window "1ms" 2025/03/07 11:12:51 DEBUG : fg45q1rm3kh00nmmkk4m6ihmrcnel1p7551kqhjr9bk2gtd2gbf0: Rmdir: contains trashed file: "dmuvulfij81f693ur0f1vvbvq9v6iscp56daas3m51n9li5e3470" --- PASS: TestCopyMetadata (8.22s) === RUN TestCopyMetadataNoEmptyDirs run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-filesez1jaqi'", Local "Local file system at /tmp/rclone2831462366", Modify Window "1ms" 2025/03/07 11:12:53 DEBUG : metadata sub dir: Making directory with metadata 2025/03/07 11:12:53 INFO : metadata sub dir: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2025/03/07 11:12:53 DEBUG : empty metadata sub dir: Making directory with metadata 2025/03/07 11:12:53 INFO : empty metadata sub dir: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2025/03/07 11:12:53 DEBUG : Local file system at /tmp/rclone2831462366: File to upload is small (21 bytes), uploading instead of streaming 2025/03/07 11:12:53 DEBUG : metadata sub dir/hello metadata world: md5 = baa7a013449dbba2b1ed02b5cfb4e1a2 OK 2025/03/07 11:12:53 DEBUG : metadata sub dir/hello metadata world: Size and md5 of src and dst objects identical 2025/03/07 11:12:53 INFO : metadata sub dir: Set directory modification time (using DirSetModTime) 2025/03/07 11:12:53 DEBUG : Added delayed dir = "empty metadata sub dir", newDst= 2025/03/07 11:12:53 DEBUG : Added delayed dir = "metadata sub dir", newDst= 2025/03/07 11:12:53 DEBUG : metadata sub dir/hello metadata world: Need to transfer - File not found at Destination 2025/03/07 11:12:53 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-filesez1jaqi': Waiting for checks to finish 2025/03/07 11:12:53 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-filesez1jaqi': Waiting for transfers to finish 2025/03/07 11:12:56 DEBUG : metadata sub dir/hello metadata world: md5 = ce36e87aff58e66f2b3b5c3d8d55772d OK 2025/03/07 11:12:56 INFO : metadata sub dir/hello metadata world: Copied (new) 2025/03/07 11:12:56 DEBUG : Google drive root 'crypt/ippqhs6o8n8f9aihb4n2s696sijniukgi2cvh83jmt0ape415uj0': Skipping btime metadata as can't update it on an existing file: 2025-03-07T11:12:53.738545125Z 2025/03/07 11:12:57 INFO : metadata sub dir: Updated directory metadata run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-filesez1jaqi'", Local "Local file system at /tmp/rclone2831462366", Modify Window "1ms" 2025/03/07 11:13:00 DEBUG : fg45q1rm3kh00nmmkk4m6ihmrcnel1p7551kqhjr9bk2gtd2gbf0: Rmdir: contains trashed file: "dmuvulfij81f693ur0f1vvbvq9v6iscp56daas3m51n9li5e3470" --- PASS: TestCopyMetadataNoEmptyDirs (7.57s) === RUN TestCopyMissingDirectory run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-filesez1jaqi'", Local "Local file system at /tmp/rclone2831462366", Modify Window "1ms" 2025/03/07 11:13:01 DEBUG : Creating backend with remote "/non-existing" 2025/03/07 11:13:01 ERROR : Local file system at /non-existing: error reading source root directory: directory not found 2025/03/07 11:13:01 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-filesez1jaqi': Waiting for checks to finish 2025/03/07 11:13:01 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-filesez1jaqi': Waiting for transfers to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-filesez1jaqi'", Local "Local file system at /tmp/rclone2831462366", Modify Window "1ms" --- PASS: TestCopyMissingDirectory (1.23s) === RUN TestCopyNoTraverse run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-filesez1jaqi'", Local "Local file system at /tmp/rclone2831462366", Modify Window "1ms" 2025/03/07 11:13:02 DEBUG : Added delayed dir = "sub dir", newDst= 2025/03/07 11:13:02 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2025/03/07 11:13:02 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-filesez1jaqi': Waiting for checks to finish 2025/03/07 11:13:02 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-filesez1jaqi': Waiting for transfers to finish 2025/03/07 11:13:05 DEBUG : sub dir/hello world: md5 = f8d4843d6b08b994fda2c8d085df6efd OK 2025/03/07 11:13:05 INFO : sub dir/hello world: Copied (new) 2025/03/07 11:13:06 INFO : sub dir: Set directory modification time (using DirSetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-filesez1jaqi'", Local "Local file system at /tmp/rclone2831462366", Modify Window "1ms" 2025/03/07 11:13:07 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestCopyNoTraverse (6.54s) === RUN TestCopyCheckFirst run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-filesez1jaqi'", Local "Local file system at /tmp/rclone2831462366", Modify Window "1ms" 2025/03/07 11:13:09 INFO : Encrypted drive 'TestCryptDrive:rclone-test-filesez1jaqi': Running all checks before starting transfers 2025/03/07 11:13:09 DEBUG : Added delayed dir = "sub dir", newDst= 2025/03/07 11:13:09 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2025/03/07 11:13:09 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-filesez1jaqi': Waiting for checks to finish 2025/03/07 11:13:09 INFO : Encrypted drive 'TestCryptDrive:rclone-test-filesez1jaqi': Checks finished, now starting transfers 2025/03/07 11:13:09 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-filesez1jaqi': Waiting for transfers to finish 2025/03/07 11:13:11 DEBUG : sub dir/hello world: md5 = c706128d8b3d94e0ea65e06ae369477a OK 2025/03/07 11:13:11 INFO : sub dir/hello world: Copied (new) 2025/03/07 11:13:12 INFO : sub dir: Set directory modification time (using DirSetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-filesez1jaqi'", Local "Local file system at /tmp/rclone2831462366", Modify Window "1ms" 2025/03/07 11:13:13 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestCopyCheckFirst (6.15s) === RUN TestSyncNoTraverse run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-filesez1jaqi'", Local "Local file system at /tmp/rclone2831462366", Modify Window "1ms" 2025/03/07 11:13:15 ERROR : Ignoring --no-traverse with sync 2025/03/07 11:13:15 DEBUG : Added delayed dir = "sub dir", newDst= 2025/03/07 11:13:15 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2025/03/07 11:13:15 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-filesez1jaqi': Waiting for checks to finish 2025/03/07 11:13:15 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-filesez1jaqi': Waiting for transfers to finish 2025/03/07 11:13:17 DEBUG : sub dir/hello world: md5 = 73c967d2f689f59a77fff4460c3183bc OK 2025/03/07 11:13:17 INFO : sub dir/hello world: Copied (new) 2025/03/07 11:13:17 DEBUG : Waiting for deletions to finish 2025/03/07 11:13:18 INFO : sub dir: Set directory modification time (using DirSetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-filesez1jaqi'", Local "Local file system at /tmp/rclone2831462366", Modify Window "1ms" 2025/03/07 11:13:20 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestSyncNoTraverse (6.19s) === RUN TestCopyWithDepth run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-filesez1jaqi'", Local "Local file system at /tmp/rclone2831462366", Modify Window "1ms" 2025/03/07 11:13:21 DEBUG : hello world2: Need to transfer - File not found at Destination 2025/03/07 11:13:21 DEBUG : Added delayed dir = "sub dir", newDst= 2025/03/07 11:13:21 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-filesez1jaqi': Waiting for checks to finish 2025/03/07 11:13:21 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-filesez1jaqi': Waiting for transfers to finish 2025/03/07 11:13:23 DEBUG : hello world2: md5 = f9e518701921c263cd878be227517684 OK 2025/03/07 11:13:23 INFO : hello world2: Copied (new) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-filesez1jaqi'", Local "Local file system at /tmp/rclone2831462366", Modify Window "1ms" --- PASS: TestCopyWithDepth (3.50s) === RUN TestCopyWithFilesFrom run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-filesez1jaqi'", Local "Local file system at /tmp/rclone2831462366", Modify Window "1ms" 2025/03/07 11:13:25 DEBUG : potato2: Need to transfer - File not found at Destination 2025/03/07 11:13:25 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-filesez1jaqi': Waiting for checks to finish 2025/03/07 11:13:25 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-filesez1jaqi': Waiting for transfers to finish 2025/03/07 11:13:26 DEBUG : potato2: md5 = ac24bd9c4303dae1e1b202171b80d7fb OK 2025/03/07 11:13:26 INFO : potato2: Copied (new) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-filesez1jaqi'", Local "Local file system at /tmp/rclone2831462366", Modify Window "1ms" --- PASS: TestCopyWithFilesFrom (3.41s) === RUN TestCopyWithFilesFromAndNoTraverse run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-filesez1jaqi'", Local "Local file system at /tmp/rclone2831462366", Modify Window "1ms" 2025/03/07 11:13:28 DEBUG : potato2: Need to transfer - File not found at Destination 2025/03/07 11:13:28 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-filesez1jaqi': Waiting for checks to finish 2025/03/07 11:13:28 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-filesez1jaqi': Waiting for transfers to finish 2025/03/07 11:13:29 DEBUG : potato2: md5 = 3be1b77abbdb07fc18edc3d50436ad47 OK 2025/03/07 11:13:29 INFO : potato2: Copied (new) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-filesez1jaqi'", Local "Local file system at /tmp/rclone2831462366", Modify Window "1ms" --- PASS: TestCopyWithFilesFromAndNoTraverse (3.25s) === RUN TestCopyEmptyDirectories run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-filesez1jaqi'", Local "Local file system at /tmp/rclone2831462366", Modify Window "1ms" 2025/03/07 11:13:31 DEBUG : sub dir2/sub sub dir2: Making directory with metadata 2025/03/07 11:13:31 INFO : sub dir2/sub sub dir2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2025/03/07 11:13:31 INFO : sub dir2: Set directory modification time (using DirSetModTime) 2025/03/07 11:13:31 INFO : sub dir: Set directory modification time (using DirSetModTime) 2025/03/07 11:13:31 DEBUG : sub dir: Making directory with metadata 2025/03/07 11:13:32 INFO : sub dir: Made directory with metadata (mtime=2001-02-03T04:05:06.499999999Z) 2025/03/07 11:13:32 DEBUG : sub dir2: Making directory with metadata 2025/03/07 11:13:33 INFO : sub dir2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2025/03/07 11:13:33 DEBUG : sub dir2/sub sub dir2: Making directory with metadata 2025/03/07 11:13:33 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2025/03/07 11:13:34 INFO : sub dir2/sub sub dir2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2025/03/07 11:13:34 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-filesez1jaqi': Waiting for checks to finish 2025/03/07 11:13:34 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-filesez1jaqi': Waiting for transfers to finish 2025/03/07 11:13:35 DEBUG : sub dir/hello world: md5 = 37817c34ed0bddd75ae48a594b8a57a5 OK 2025/03/07 11:13:35 INFO : sub dir/hello world: Copied (new) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-filesez1jaqi'", Local "Local file system at /tmp/rclone2831462366", Modify Window "1ms" 2025/03/07 11:13:39 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc: Rmdir: contains trashed file: "cv6a9uf28ngrajena8kt5ijjn0" 2025/03/07 11:13:39 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestCopyEmptyDirectories (9.46s) === RUN TestCopyNoEmptyDirectories run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-filesez1jaqi'", Local "Local file system at /tmp/rclone2831462366", Modify Window "1ms" 2025/03/07 11:13:41 INFO : sub dir2: Making directory 2025/03/07 11:13:41 DEBUG : sub dir2/sub sub dir2: Making directory with metadata 2025/03/07 11:13:41 INFO : sub dir2/sub sub dir2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2025/03/07 11:13:41 DEBUG : Added delayed dir = "sub dir", newDst= 2025/03/07 11:13:41 DEBUG : Added delayed dir = "sub dir2", newDst= 2025/03/07 11:13:41 DEBUG : Added delayed dir = "sub dir2/sub sub dir2", newDst= 2025/03/07 11:13:41 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2025/03/07 11:13:41 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-filesez1jaqi': Waiting for checks to finish 2025/03/07 11:13:41 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-filesez1jaqi': Waiting for transfers to finish 2025/03/07 11:13:43 DEBUG : sub dir/hello world: md5 = f7fb2bcf1810b90df31a0594f1275b41 OK 2025/03/07 11:13:43 INFO : sub dir/hello world: Copied (new) 2025/03/07 11:13:44 INFO : sub dir: Set directory modification time (using DirSetModTime) 2025/03/07 11:13:45 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestCopyNoEmptyDirectories (5.74s) === RUN TestMoveEmptyDirectories run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-filesez1jaqi'", Local "Local file system at /tmp/rclone2831462366", Modify Window "1ms" 2025/03/07 11:13:46 DEBUG : sub dir2: Making directory with metadata 2025/03/07 11:13:46 INFO : sub dir2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2025/03/07 11:13:47 DEBUG : sub dir: Making directory with metadata 2025/03/07 11:13:47 INFO : sub dir: Made directory with metadata (mtime=2025-03-07T11:13:46.774205308Z) 2025/03/07 11:13:47 DEBUG : sub dir2: Making directory with metadata 2025/03/07 11:13:48 INFO : sub dir2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2025/03/07 11:13:48 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2025/03/07 11:13:48 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-filesez1jaqi': Waiting for checks to finish 2025/03/07 11:13:48 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-filesez1jaqi': Waiting for transfers to finish 2025/03/07 11:13:49 DEBUG : sub dir/hello world: md5 = 76c80816f2c9d1337fd8fc7d4e24f602 OK 2025/03/07 11:13:49 INFO : sub dir/hello world: Copied (new) 2025/03/07 11:13:49 INFO : sub dir/hello world: Deleted run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-filesez1jaqi'", Local "Local file system at /tmp/rclone2831462366", Modify Window "1ms" 2025/03/07 11:13:52 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestMoveEmptyDirectories (7.37s) === RUN TestSyncNoUpdateDirModtime run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-filesez1jaqi'", Local "Local file system at /tmp/rclone2831462366", Modify Window "1ms" 2025/03/07 11:13:54 DEBUG : sub dir no update dir modtime: Making directory with metadata 2025/03/07 11:13:54 INFO : sub dir no update dir modtime: Made directory with metadata (mtime=2001-02-03T04:05:06.499999999Z) 2025/03/07 11:13:55 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-filesez1jaqi': Waiting for checks to finish 2025/03/07 11:13:55 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-filesez1jaqi': Waiting for transfers to finish 2025/03/07 11:13:55 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-filesez1jaqi'", Local "Local file system at /tmp/rclone2831462366", Modify Window "1ms" --- PASS: TestSyncNoUpdateDirModtime (4.45s) === RUN TestMoveNoEmptyDirectories run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-filesez1jaqi'", Local "Local file system at /tmp/rclone2831462366", Modify Window "1ms" 2025/03/07 11:13:58 INFO : sub dir2: Making directory 2025/03/07 11:13:58 DEBUG : Added delayed dir = "sub dir", newDst= 2025/03/07 11:13:58 DEBUG : Added delayed dir = "sub dir2", newDst= 2025/03/07 11:13:58 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2025/03/07 11:13:58 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-filesez1jaqi': Waiting for checks to finish 2025/03/07 11:13:58 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-filesez1jaqi': Waiting for transfers to finish 2025/03/07 11:14:01 DEBUG : sub dir/hello world: md5 = 23c16412b6c499e49ce90c5717a10fe4 OK 2025/03/07 11:14:01 INFO : sub dir/hello world: Copied (new) 2025/03/07 11:14:01 INFO : sub dir/hello world: Deleted 2025/03/07 11:14:01 INFO : sub dir: Set directory modification time (using DirSetModTime) 2025/03/07 11:14:03 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestMoveNoEmptyDirectories (5.47s) === RUN TestSyncEmptyDirectories run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-filesez1jaqi'", Local "Local file system at /tmp/rclone2831462366", Modify Window "1ms" 2025/03/07 11:14:04 DEBUG : sub dir2: Making directory with metadata 2025/03/07 11:14:04 INFO : sub dir2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2025/03/07 11:14:04 INFO : sub dir: Set directory modification time (using DirSetModTime) 2025/03/07 11:14:04 DEBUG : sub dir: Making directory with metadata 2025/03/07 11:14:05 INFO : sub dir: Made directory with metadata (mtime=2001-02-03T04:05:06.499999999Z) 2025/03/07 11:14:05 DEBUG : sub dir2: Making directory with metadata 2025/03/07 11:14:05 INFO : sub dir2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2025/03/07 11:14:05 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2025/03/07 11:14:05 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-filesez1jaqi': Waiting for checks to finish 2025/03/07 11:14:05 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-filesez1jaqi': Waiting for transfers to finish 2025/03/07 11:14:07 DEBUG : sub dir/hello world: md5 = b867e63fee226b37c483a120c90f0254 OK 2025/03/07 11:14:07 INFO : sub dir/hello world: Copied (new) 2025/03/07 11:14:07 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-filesez1jaqi'", Local "Local file system at /tmp/rclone2831462366", Modify Window "1ms" 2025/03/07 11:14:10 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestSyncEmptyDirectories (7.50s) === RUN TestSyncSetDelayedModTimes run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-filesez1jaqi'", Local "Local file system at /tmp/rclone2831462366", Modify Window "1ms" sync_test.go:507: Backend doesn't have DirModTimeUpdatesOnWrite set --- SKIP: TestSyncSetDelayedModTimes (0.45s) === RUN TestSyncNoEmptyDirectories run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-filesez1jaqi'", Local "Local file system at /tmp/rclone2831462366", Modify Window "1ms" 2025/03/07 11:14:12 INFO : sub dir2: Making directory 2025/03/07 11:14:12 DEBUG : Added delayed dir = "sub dir", newDst= 2025/03/07 11:14:12 DEBUG : Added delayed dir = "sub dir2", newDst= 2025/03/07 11:14:12 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2025/03/07 11:14:12 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-filesez1jaqi': Waiting for checks to finish 2025/03/07 11:14:12 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-filesez1jaqi': Waiting for transfers to finish 2025/03/07 11:14:14 DEBUG : sub dir/hello world: md5 = 442448b30e0be82abab8c2e418c0f287 OK 2025/03/07 11:14:14 INFO : sub dir/hello world: Copied (new) 2025/03/07 11:14:14 DEBUG : Waiting for deletions to finish 2025/03/07 11:14:15 INFO : sub dir: Set directory modification time (using DirSetModTime) 2025/03/07 11:14:16 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestSyncNoEmptyDirectories (5.55s) === RUN TestServerSideCopy run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-filesez1jaqi'", Local "Local file system at /tmp/rclone2831462366", Modify Window "1ms" 2025/03/07 11:14:20 DEBUG : sub dir/hello world: md5 = f6af1cad3077c8d6fa466542ac9cafd5 OK 2025/03/07 11:14:20 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-qusafim9zegu" 2025/03/07 11:14:20 DEBUG : Creating backend with remote "TestDrive:crypt/d1vkdtmpl2sgu79serq5hmnqgntmpa38ncod6himc3leufvjai80" sync_test.go:590: Server side copy (if possible) Encrypted drive 'TestCryptDrive:rclone-test-filesez1jaqi' -> Encrypted drive 'TestCryptDrive:rclone-test-qusafim9zegu' 2025/03/07 11:14:21 DEBUG : Added delayed dir = "sub dir", newDst= 2025/03/07 11:14:22 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2025/03/07 11:14:22 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-qusafim9zegu': Waiting for checks to finish 2025/03/07 11:14:22 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-qusafim9zegu': Waiting for transfers to finish 2025/03/07 11:14:25 INFO : sub dir/hello world: Copied (server-side copy) 2025/03/07 11:14:25 INFO : sub dir: Set directory modification time (using DirSetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-filesez1jaqi'", Local "Local file system at /tmp/rclone2831462366", Modify Window "1ms" 2025/03/07 11:14:26 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-qusafim9zegu': Purge remote 2025/03/07 11:14:28 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestServerSideCopy (11.66s) === RUN TestCopyOverSelf run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-filesez1jaqi'", Local "Local file system at /tmp/rclone2831462366", Modify Window "1ms" 2025/03/07 11:14:31 DEBUG : sub dir/hello world: md5 = 77f4c3270509543ed0ca042dc466aecf OK 2025/03/07 11:14:32 INFO : sub dir: Set directory modification time (using SetModTime) 2025/03/07 11:14:32 DEBUG : Added delayed dir = "sub dir", newDst=sub dir 2025/03/07 11:14:32 DEBUG : sub dir/hello world: Sizes differ (src 17 vs dst 11) 2025/03/07 11:14:32 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-filesez1jaqi': Waiting for checks to finish 2025/03/07 11:14:32 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-filesez1jaqi': Waiting for transfers to finish 2025/03/07 11:14:34 DEBUG : sub dir/hello world: md5 = 2aa304136cbccf69bf3971442091e0b3 OK 2025/03/07 11:14:34 INFO : sub dir/hello world: Copied (replaced existing) 2025/03/07 11:14:34 INFO : sub dir: Set directory modification time (using SetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-filesez1jaqi'", Local "Local file system at /tmp/rclone2831462366", Modify Window "1ms" 2025/03/07 11:14:36 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestCopyOverSelf (8.17s) === RUN TestServerSideCopyOverSelf run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-filesez1jaqi'", Local "Local file system at /tmp/rclone2831462366", Modify Window "1ms" 2025/03/07 11:14:39 DEBUG : sub dir/hello world: md5 = 09728c1dc338a17639fb99f9eb4e3ee9 OK 2025/03/07 11:14:40 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-zofavoh0jiwi" 2025/03/07 11:14:40 DEBUG : Creating backend with remote "TestDrive:crypt/apgo3o8ek5juihar53luj7mug8figm6oo3isvtv8ljrkfg7tkt6g" sync_test.go:626: Server side copy (if possible) Encrypted drive 'TestCryptDrive:rclone-test-filesez1jaqi' -> Encrypted drive 'TestCryptDrive:rclone-test-zofavoh0jiwi' 2025/03/07 11:14:41 DEBUG : Added delayed dir = "sub dir", newDst= 2025/03/07 11:14:41 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2025/03/07 11:14:41 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zofavoh0jiwi': Waiting for checks to finish 2025/03/07 11:14:41 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zofavoh0jiwi': Waiting for transfers to finish 2025/03/07 11:14:44 INFO : sub dir/hello world: Copied (server-side copy) 2025/03/07 11:14:44 INFO : sub dir: Set directory modification time (using DirSetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-filesez1jaqi'", Local "Local file system at /tmp/rclone2831462366", Modify Window "1ms" 2025/03/07 11:14:47 DEBUG : sub dir/hello world: md5 = 9a63a0e30263421aa4eeb16a85eb16ff OK 2025/03/07 11:14:47 DEBUG : sub dir: Directory modification time the same (differ by 0s, within tolerance 1ms) 2025/03/07 11:14:47 DEBUG : Added delayed dir = "sub dir", newDst=sub dir 2025/03/07 11:14:47 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zofavoh0jiwi': Waiting for checks to finish 2025/03/07 11:14:47 DEBUG : sub dir/hello world: Sizes differ (src 17 vs dst 11) 2025/03/07 11:14:47 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zofavoh0jiwi': Waiting for transfers to finish 2025/03/07 11:14:49 INFO : sub dir/hello world: Copied (server-side copy) 2025/03/07 11:14:49 INFO : sub dir: Set directory modification time (using SetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-filesez1jaqi'", Local "Local file system at /tmp/rclone2831462366", Modify Window "1ms" 2025/03/07 11:14:50 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zofavoh0jiwi': Purge remote 2025/03/07 11:14:52 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestServerSideCopyOverSelf (16.55s) === RUN TestMoveOverSelf run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-filesez1jaqi'", Local "Local file system at /tmp/rclone2831462366", Modify Window "1ms" 2025/03/07 11:14:56 DEBUG : sub dir/hello world: md5 = 54275ae4da579d230e3330ff4b15b5a3 OK 2025/03/07 11:14:57 INFO : sub dir: Set directory modification time (using SetModTime) 2025/03/07 11:14:57 DEBUG : Added delayed dir = "sub dir", newDst=sub dir 2025/03/07 11:14:57 DEBUG : sub dir/hello world: Sizes differ (src 17 vs dst 11) 2025/03/07 11:14:57 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-filesez1jaqi': Waiting for checks to finish 2025/03/07 11:14:57 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-filesez1jaqi': Waiting for transfers to finish 2025/03/07 11:14:58 DEBUG : sub dir/hello world: md5 = b62744afca4a8221e1f42b9c4f3083d8 OK 2025/03/07 11:14:58 INFO : sub dir/hello world: Copied (replaced existing) 2025/03/07 11:14:58 INFO : sub dir/hello world: Deleted 2025/03/07 11:14:59 INFO : sub dir: Set directory modification time (using SetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-filesez1jaqi'", Local "Local file system at /tmp/rclone2831462366", Modify Window "1ms" 2025/03/07 11:15:00 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestMoveOverSelf (8.28s) === RUN TestServerSideMoveOverSelf run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-filesez1jaqi'", Local "Local file system at /tmp/rclone2831462366", Modify Window "1ms" 2025/03/07 11:15:04 DEBUG : sub dir/hello world: md5 = 5816c79d54c5cdafa9934dc7dbbbd1ce OK 2025/03/07 11:15:04 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-pidociw7gipi" 2025/03/07 11:15:04 DEBUG : Creating backend with remote "TestDrive:crypt/rpkt4ruuek6tbt8u1qat6d9ngotklded3lh3jc7sl1kme1fhvjtg" sync_test.go:671: Server side copy (if possible) Encrypted drive 'TestCryptDrive:rclone-test-filesez1jaqi' -> Encrypted drive 'TestCryptDrive:rclone-test-pidociw7gipi' 2025/03/07 11:15:06 DEBUG : Added delayed dir = "sub dir", newDst= 2025/03/07 11:15:06 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2025/03/07 11:15:06 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pidociw7gipi': Waiting for checks to finish 2025/03/07 11:15:06 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pidociw7gipi': Waiting for transfers to finish 2025/03/07 11:15:09 INFO : sub dir/hello world: Copied (server-side copy) 2025/03/07 11:15:09 INFO : sub dir: Set directory modification time (using DirSetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-filesez1jaqi'", Local "Local file system at /tmp/rclone2831462366", Modify Window "1ms" 2025/03/07 11:15:11 DEBUG : sub dir/hello world: md5 = af9939fad4dfe603cbf54c0dd4096256 OK 2025/03/07 11:15:12 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pidociw7gipi': Using server-side directory move 2025/03/07 11:15:12 INFO : Encrypted drive 'TestCryptDrive:rclone-test-pidociw7gipi': Server side directory move failed - fallback to file moves: can't copy directory - destination already exists 2025/03/07 11:15:12 DEBUG : sub dir: Directory modification time the same (differ by 0s, within tolerance 1ms) 2025/03/07 11:15:12 DEBUG : Added delayed dir = "sub dir", newDst=sub dir 2025/03/07 11:15:12 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pidociw7gipi': Waiting for checks to finish 2025/03/07 11:15:12 DEBUG : sub dir/hello world: Sizes differ (src 17 vs dst 11) 2025/03/07 11:15:12 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pidociw7gipi': Waiting for transfers to finish 2025/03/07 11:15:13 INFO : sub dir/hello world: Deleted 2025/03/07 11:15:13 INFO : sub dir/hello world: Moved (server-side) 2025/03/07 11:15:14 INFO : sub dir: Set directory modification time (using SetModTime) 2025/03/07 11:15:17 DEBUG : sub dir/hello world: md5 = 32c68cfe26c79e649c0947eed41e7a58 OK 2025/03/07 11:15:17 DEBUG : testing file moves 2025/03/07 11:15:17 DEBUG : sub dir: Directory modification time the same (differ by 0s, within tolerance 1ms) 2025/03/07 11:15:17 DEBUG : Added delayed dir = "sub dir", newDst=sub dir 2025/03/07 11:15:17 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pidociw7gipi': Waiting for checks to finish 2025/03/07 11:15:17 DEBUG : sub dir/hello world: Sizes differ (src 24 vs dst 17) 2025/03/07 11:15:17 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pidociw7gipi': Waiting for transfers to finish 2025/03/07 11:15:18 INFO : sub dir/hello world: Deleted 2025/03/07 11:15:19 INFO : sub dir/hello world: Moved (server-side) 2025/03/07 11:15:19 INFO : sub dir: Set directory modification time (using SetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-filesez1jaqi'", Local "Local file system at /tmp/rclone2831462366", Modify Window "1ms" 2025/03/07 11:15:20 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pidociw7gipi': Purge remote --- PASS: TestServerSideMoveOverSelf (21.49s) === RUN TestCopyAfterDelete run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-filesez1jaqi'", Local "Local file system at /tmp/rclone2831462366", Modify Window "1ms" 2025/03/07 11:15:25 DEBUG : sub dir/hello world: md5 = f2ad6c389e26556a560f0045404360f8 OK 2025/03/07 11:15:25 ERROR : : error listing: directory not found 2025/03/07 11:15:26 INFO : Local file system at /tmp/rclone2831462366: Making directory 2025/03/07 11:15:26 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-filesez1jaqi': Waiting for checks to finish 2025/03/07 11:15:26 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-filesez1jaqi': Waiting for transfers to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-filesez1jaqi'", Local "Local file system at /tmp/rclone2831462366", Modify Window "1ms" 2025/03/07 11:15:28 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestCopyAfterDelete (5.93s) === RUN TestCopyRedownload run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-filesez1jaqi'", Local "Local file system at /tmp/rclone2831462366", Modify Window "1ms" 2025/03/07 11:15:32 DEBUG : sub dir/hello world: md5 = fa9da63b0b957943e1a29550794b216d OK 2025/03/07 11:15:33 DEBUG : Added delayed dir = "sub dir", newDst= 2025/03/07 11:15:33 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2025/03/07 11:15:33 DEBUG : Local file system at /tmp/rclone2831462366: Waiting for checks to finish 2025/03/07 11:15:33 DEBUG : Local file system at /tmp/rclone2831462366: Waiting for transfers to finish 2025/03/07 11:15:34 DEBUG : sub dir/hello world.285f0a30.partial: renamed to: sub dir/hello world 2025/03/07 11:15:34 INFO : sub dir/hello world: Copied (new) 2025/03/07 11:15:34 INFO : sub dir: Set directory modification time (using DirSetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-filesez1jaqi'", Local "Local file system at /tmp/rclone2831462366", Modify Window "1ms" 2025/03/07 11:15:35 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestCopyRedownload (7.41s) === RUN TestSyncBasedOnCheckSum run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-filesez1jaqi'", Local "Local file system at /tmp/rclone2831462366", Modify Window "1ms" 2025/03/07 11:15:37 DEBUG : check sum: Need to transfer - File not found at Destination 2025/03/07 11:15:37 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-filesez1jaqi': Waiting for checks to finish 2025/03/07 11:15:37 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-filesez1jaqi': Waiting for transfers to finish 2025/03/07 11:15:38 DEBUG : check sum: md5 = 6f116c41c1c379ef4c282044c325a057 OK 2025/03/07 11:15:38 INFO : check sum: Copied (new) 2025/03/07 11:15:38 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-filesez1jaqi'", Local "Local file system at /tmp/rclone2831462366", Modify Window "1ms" 2025/03/07 11:15:39 NOTICE: Encrypted drive 'TestCryptDrive:rclone-test-filesez1jaqi': --checksum is in use but the source and destination have no hashes in common; falling back to --size-only 2025/03/07 11:15:39 DEBUG : check sum: Size of src and dst objects identical 2025/03/07 11:15:39 DEBUG : check sum: Unchanged skipping 2025/03/07 11:15:39 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-filesez1jaqi': Waiting for checks to finish 2025/03/07 11:15:39 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-filesez1jaqi': Waiting for transfers to finish 2025/03/07 11:15:39 DEBUG : Waiting for deletions to finish 2025/03/07 11:15:39 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-filesez1jaqi'", Local "Local file system at /tmp/rclone2831462366", Modify Window "1ms" --- PASS: TestSyncBasedOnCheckSum (4.28s) === RUN TestSyncSizeOnly run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-filesez1jaqi'", Local "Local file system at /tmp/rclone2831462366", Modify Window "1ms" 2025/03/07 11:15:41 DEBUG : sizeonly: Need to transfer - File not found at Destination 2025/03/07 11:15:41 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-filesez1jaqi': Waiting for checks to finish 2025/03/07 11:15:41 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-filesez1jaqi': Waiting for transfers to finish 2025/03/07 11:15:43 DEBUG : sizeonly: md5 = 08a385cc1973af5875abcfe270553af5 OK 2025/03/07 11:15:43 INFO : sizeonly: Copied (new) 2025/03/07 11:15:43 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-filesez1jaqi'", Local "Local file system at /tmp/rclone2831462366", Modify Window "1ms" 2025/03/07 11:15:43 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-filesez1jaqi': Waiting for checks to finish 2025/03/07 11:15:43 DEBUG : sizeonly: Sizes identical 2025/03/07 11:15:43 DEBUG : sizeonly: Unchanged skipping 2025/03/07 11:15:43 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-filesez1jaqi': Waiting for transfers to finish 2025/03/07 11:15:43 DEBUG : Waiting for deletions to finish 2025/03/07 11:15:43 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-filesez1jaqi'", Local "Local file system at /tmp/rclone2831462366", Modify Window "1ms" --- PASS: TestSyncSizeOnly (4.57s) === RUN TestSyncIgnoreSize run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-filesez1jaqi'", Local "Local file system at /tmp/rclone2831462366", Modify Window "1ms" 2025/03/07 11:15:46 DEBUG : ignore-size: Need to transfer - File not found at Destination 2025/03/07 11:15:46 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-filesez1jaqi': Waiting for checks to finish 2025/03/07 11:15:46 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-filesez1jaqi': Waiting for transfers to finish 2025/03/07 11:15:47 DEBUG : ignore-size: md5 = 80f03bf3f2a4e4cfdf939d7497e135ac OK 2025/03/07 11:15:47 INFO : ignore-size: Copied (new) 2025/03/07 11:15:47 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-filesez1jaqi'", Local "Local file system at /tmp/rclone2831462366", Modify Window "1ms" 2025/03/07 11:15:48 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-filesez1jaqi': Waiting for checks to finish 2025/03/07 11:15:48 DEBUG : ignore-size: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/03/07 11:15:48 DEBUG : ignore-size: Unchanged skipping 2025/03/07 11:15:48 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-filesez1jaqi': Waiting for transfers to finish 2025/03/07 11:15:48 DEBUG : Waiting for deletions to finish 2025/03/07 11:15:48 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-filesez1jaqi'", Local "Local file system at /tmp/rclone2831462366", Modify Window "1ms" --- PASS: TestSyncIgnoreSize (4.51s) === RUN TestSyncIgnoreTimes run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-filesez1jaqi'", Local "Local file system at /tmp/rclone2831462366", Modify Window "1ms" 2025/03/07 11:15:51 DEBUG : existing: md5 = 850c57420aa722be7323297926f5b354 OK 2025/03/07 11:15:52 DEBUG : existing: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/03/07 11:15:52 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-filesez1jaqi': Waiting for checks to finish 2025/03/07 11:15:52 DEBUG : existing: Unchanged skipping 2025/03/07 11:15:52 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-filesez1jaqi': Waiting for transfers to finish 2025/03/07 11:15:52 DEBUG : Waiting for deletions to finish 2025/03/07 11:15:52 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-filesez1jaqi'", Local "Local file system at /tmp/rclone2831462366", Modify Window "1ms" 2025/03/07 11:15:52 DEBUG : existing: Transferring unconditionally as --ignore-times is in use 2025/03/07 11:15:52 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-filesez1jaqi': Waiting for checks to finish 2025/03/07 11:15:52 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-filesez1jaqi': Waiting for transfers to finish 2025/03/07 11:15:53 DEBUG : existing: md5 = f94e5081b95019076764eba045d8c0ec OK 2025/03/07 11:15:53 INFO : existing: Copied (replaced existing) 2025/03/07 11:15:53 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-filesez1jaqi'", Local "Local file system at /tmp/rclone2831462366", Modify Window "1ms" --- PASS: TestSyncIgnoreTimes (5.46s) === RUN TestSyncIgnoreExisting run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-filesez1jaqi'", Local "Local file system at /tmp/rclone2831462366", Modify Window "1ms" 2025/03/07 11:15:56 DEBUG : existing: Need to transfer - File not found at Destination 2025/03/07 11:15:56 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-filesez1jaqi': Waiting for checks to finish 2025/03/07 11:15:56 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-filesez1jaqi': Waiting for transfers to finish 2025/03/07 11:15:57 DEBUG : existing: md5 = da917a85aea574cb00cc7492e0b97906 OK 2025/03/07 11:15:57 INFO : existing: Copied (new) 2025/03/07 11:15:57 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-filesez1jaqi'", Local "Local file system at /tmp/rclone2831462366", Modify Window "1ms" 2025/03/07 11:15:58 DEBUG : existing: Destination exists, skipping 2025/03/07 11:15:58 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-filesez1jaqi': Waiting for checks to finish 2025/03/07 11:15:58 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-filesez1jaqi': Waiting for transfers to finish 2025/03/07 11:15:58 DEBUG : Waiting for deletions to finish 2025/03/07 11:15:58 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-filesez1jaqi'", Local "Local file system at /tmp/rclone2831462366", Modify Window "1ms" --- PASS: TestSyncIgnoreExisting (4.60s) === RUN TestSyncIgnoreErrors run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-filesez1jaqi'", Local "Local file system at /tmp/rclone2831462366", Modify Window "1ms" 2025/03/07 11:16:02 DEBUG : b/potato: md5 = 68b3f20e494df5d7550cf52612565099 OK 2025/03/07 11:16:04 DEBUG : c/non empty space: md5 = 6619ddcc12c42e4627cb7bf9d55db518 OK 2025/03/07 11:16:04 INFO : d: Making directory 2025/03/07 11:16:06 DEBUG : Added delayed dir = "a", newDst= 2025/03/07 11:16:07 INFO : c: Set directory modification time (using SetModTime) 2025/03/07 11:16:07 DEBUG : Added delayed dir = "c", newDst=c 2025/03/07 11:16:07 DEBUG : a/potato2: Need to transfer - File not found at Destination 2025/03/07 11:16:07 DEBUG : c/non empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/03/07 11:16:07 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-filesez1jaqi': Waiting for checks to finish 2025/03/07 11:16:07 DEBUG : c/non empty space: Unchanged skipping 2025/03/07 11:16:07 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-filesez1jaqi': Waiting for transfers to finish 2025/03/07 11:16:09 DEBUG : a/potato2: md5 = 0d4c503a4cf84259a33e511cb08ba9bd OK 2025/03/07 11:16:09 INFO : a/potato2: Copied (new) 2025/03/07 11:16:09 DEBUG : Waiting for deletions to finish 2025/03/07 11:16:09 INFO : b/potato: Deleted 2025/03/07 11:16:10 INFO : a: Set directory modification time (using DirSetModTime) 2025/03/07 11:16:10 INFO : d: Removing directory 2025/03/07 11:16:11 INFO : b: Removing directory 2025/03/07 11:16:11 DEBUG : 32d8ua6196mc1r7qkfog53rkg0: Rmdir: contains trashed file: "2m507n64kafsi59v9q71r281a4" 2025/03/07 11:16:11 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-filesez1jaqi': deleted 2 directories run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-filesez1jaqi'", Local "Local file system at /tmp/rclone2831462366", Modify Window "1ms" 2025/03/07 11:16:14 DEBUG : 3i9du405pfogq3ncai6pg7ouio: Rmdir: contains trashed file: "982d3pss7t5pn0il16r2foj31s" 2025/03/07 11:16:14 DEBUG : 2bsvlrk2ne1lfitm6tttcu0qt8: Rmdir: contains trashed file: "89l8renevh3mji1c8r1p7qn6tg" --- PASS: TestSyncIgnoreErrors (15.48s) === RUN TestSyncAfterChangingModtimeOnly run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-filesez1jaqi'", Local "Local file system at /tmp/rclone2831462366", Modify Window "1ms" 2025/03/07 11:16:17 DEBUG : empty space: md5 = 4af188132d1d00bcc5e2fe75d17c3bd0 OK 2025/03/07 11:16:17 DEBUG : empty space: Modification times differ by -95456h54m52.624456789s: 2011-12-25 12:59:59.123456789 +0000 UTC, 2001-02-03 04:05:06.499 +0000 UTC 2025/03/07 11:16:17 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-filesez1jaqi': Waiting for checks to finish 2025/03/07 11:16:17 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-filesez1jaqi': Waiting for transfers to finish 2025/03/07 11:16:17 NOTICE: empty space: Skipped copy as --dry-run is set (size 1) 2025/03/07 11:16:17 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-filesez1jaqi'", Local "Local file system at /tmp/rclone2831462366", Modify Window "1ms" 2025/03/07 11:16:18 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-filesez1jaqi': Waiting for checks to finish 2025/03/07 11:16:18 DEBUG : empty space: Modification times differ by -95456h54m52.624456789s: 2011-12-25 12:59:59.123456789 +0000 UTC, 2001-02-03 04:05:06.499 +0000 UTC 2025/03/07 11:16:18 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-filesez1jaqi': Waiting for transfers to finish 2025/03/07 11:16:19 DEBUG : empty space: md5 = 5471ae71fe6b9b7fd8b116145ab64cb9 OK 2025/03/07 11:16:19 INFO : empty space: Copied (replaced existing) 2025/03/07 11:16:19 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-filesez1jaqi'", Local "Local file system at /tmp/rclone2831462366", Modify Window "1ms" --- PASS: TestSyncAfterChangingModtimeOnly (6.10s) === RUN TestSyncAfterChangingModtimeOnlyWithNoUpdateModTime run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-filesez1jaqi'", Local "Local file system at /tmp/rclone2831462366", Modify Window "1ms" sync_test.go:1016: Can't check this if no hashes supported --- PASS: TestSyncAfterChangingModtimeOnlyWithNoUpdateModTime (0.43s) === RUN TestSyncDoesntUpdateModtime run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-filesez1jaqi'", Local "Local file system at /tmp/rclone2831462366", Modify Window "1ms" 2025/03/07 11:16:23 DEBUG : foo: md5 = 956b425516bf14a02277a9f909d27293 OK 2025/03/07 11:16:24 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-filesez1jaqi': Waiting for checks to finish 2025/03/07 11:16:24 DEBUG : foo: Modification times differ by -95456h54m52.624456789s: 2011-12-25 12:59:59.123456789 +0000 UTC, 2001-02-03 04:05:06.499 +0000 UTC 2025/03/07 11:16:24 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-filesez1jaqi': Waiting for transfers to finish 2025/03/07 11:16:25 DEBUG : foo: md5 = a9300b1598d5bf95e90c7b138396b7c6 OK 2025/03/07 11:16:25 INFO : foo: Copied (replaced existing) 2025/03/07 11:16:25 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-filesez1jaqi'", Local "Local file system at /tmp/rclone2831462366", Modify Window "1ms" --- PASS: TestSyncDoesntUpdateModtime (4.91s) === RUN TestSyncAfterAddingAFile run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-filesez1jaqi'", Local "Local file system at /tmp/rclone2831462366", Modify Window "1ms" 2025/03/07 11:16:28 DEBUG : empty space: md5 = fbe9175177dc93fc1883601bfc71b500 OK 2025/03/07 11:16:29 DEBUG : potato: Need to transfer - File not found at Destination 2025/03/07 11:16:29 DEBUG : empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/03/07 11:16:29 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-filesez1jaqi': Waiting for checks to finish 2025/03/07 11:16:29 DEBUG : empty space: Unchanged skipping 2025/03/07 11:16:29 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-filesez1jaqi': Waiting for transfers to finish 2025/03/07 11:16:30 DEBUG : potato: md5 = e7bd3237aba301c2f8d7b452131456a7 OK 2025/03/07 11:16:30 INFO : potato: Copied (new) 2025/03/07 11:16:30 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-filesez1jaqi'", Local "Local file system at /tmp/rclone2831462366", Modify Window "1ms" --- PASS: TestSyncAfterAddingAFile (5.36s) === RUN TestSyncAfterChangingFilesSizeOnly run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-filesez1jaqi'", Local "Local file system at /tmp/rclone2831462366", Modify Window "1ms" 2025/03/07 11:16:34 DEBUG : potato: md5 = abc2e03bfba8315d61cf36135a3d75fc OK 2025/03/07 11:16:34 DEBUG : potato: Sizes differ (src 21 vs dst 60) 2025/03/07 11:16:34 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-filesez1jaqi': Waiting for checks to finish 2025/03/07 11:16:34 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-filesez1jaqi': Waiting for transfers to finish 2025/03/07 11:16:35 DEBUG : potato: md5 = 05340f6e8756d1e5d85b7c2c73ed5ca3 OK 2025/03/07 11:16:35 INFO : potato: Copied (replaced existing) 2025/03/07 11:16:35 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-filesez1jaqi'", Local "Local file system at /tmp/rclone2831462366", Modify Window "1ms" --- PASS: TestSyncAfterChangingFilesSizeOnly (4.89s) === RUN TestSyncAfterChangingContentsOnly run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-filesez1jaqi'", Local "Local file system at /tmp/rclone2831462366", Modify Window "1ms" 2025/03/07 11:16:39 DEBUG : potato: md5 = ee0cf30f409fc61f9a69b8e91290eaf4 OK 2025/03/07 11:16:39 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-filesez1jaqi': Waiting for checks to finish 2025/03/07 11:16:39 DEBUG : potato: Modification times differ by 119h59m59.876543211s: 2011-12-25 12:59:59.123456789 +0000 UTC, 2011-12-30 12:59:59 +0000 UTC 2025/03/07 11:16:39 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-filesez1jaqi': Waiting for transfers to finish 2025/03/07 11:16:40 DEBUG : potato: md5 = 9c419faa59c58940ff265102f4e0916f OK 2025/03/07 11:16:40 INFO : potato: Copied (replaced existing) 2025/03/07 11:16:40 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-filesez1jaqi'", Local "Local file system at /tmp/rclone2831462366", Modify Window "1ms" --- PASS: TestSyncAfterChangingContentsOnly (4.93s) === RUN TestSyncAfterRemovingAFileAndAddingAFileDryRun run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-filesez1jaqi'", Local "Local file system at /tmp/rclone2831462366", Modify Window "1ms" 2025/03/07 11:16:43 DEBUG : potato: md5 = a13fcc382314a77c538c42d3abc40c23 OK 2025/03/07 11:16:45 DEBUG : empty space: md5 = 6930fb82fcd538a7366f604fdfba95e1 OK 2025/03/07 11:16:45 DEBUG : potato2: Need to transfer - File not found at Destination 2025/03/07 11:16:45 NOTICE: potato2: Skipped copy as --dry-run is set (size 60) 2025/03/07 11:16:45 DEBUG : empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/03/07 11:16:45 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-filesez1jaqi': Waiting for checks to finish 2025/03/07 11:16:45 DEBUG : empty space: Unchanged skipping 2025/03/07 11:16:45 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-filesez1jaqi': Waiting for transfers to finish 2025/03/07 11:16:45 DEBUG : Waiting for deletions to finish 2025/03/07 11:16:45 NOTICE: potato: Skipped delete as --dry-run is set (size 21) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-filesez1jaqi'", Local "Local file system at /tmp/rclone2831462366", Modify Window "1ms" --- PASS: TestSyncAfterRemovingAFileAndAddingAFileDryRun (5.07s) === RUN TestSyncAfterRemovingAFileAndAddingAFile run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-filesez1jaqi'", Local "Local file system at /tmp/rclone2831462366", Modify Window "1ms" 2025/03/07 11:16:49 DEBUG : potato: md5 = e7de8505042caae3d15011fe7f9b6a8c OK 2025/03/07 11:16:50 DEBUG : empty space: md5 = 3b542b93d50ff41ba68c331258e32c75 OK 2025/03/07 11:16:51 DEBUG : potato2: Need to transfer - File not found at Destination 2025/03/07 11:16:51 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-filesez1jaqi': Waiting for checks to finish 2025/03/07 11:16:51 DEBUG : empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/03/07 11:16:51 DEBUG : empty space: Unchanged skipping 2025/03/07 11:16:51 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-filesez1jaqi': Waiting for transfers to finish 2025/03/07 11:16:52 DEBUG : potato2: md5 = 9dbea110209f21e94094401e1a81bf72 OK 2025/03/07 11:16:52 INFO : potato2: Copied (new) 2025/03/07 11:16:52 DEBUG : Waiting for deletions to finish 2025/03/07 11:16:53 INFO : potato: Deleted run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-filesez1jaqi'", Local "Local file system at /tmp/rclone2831462366", Modify Window "1ms" --- PASS: TestSyncAfterRemovingAFileAndAddingAFile (7.82s) === RUN TestSyncAfterRemovingAFileAndAddingAFileSubDir run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-filesez1jaqi'", Local "Local file system at /tmp/rclone2831462366", Modify Window "1ms" 2025/03/07 11:16:57 DEBUG : b/potato: md5 = db5f3a5e1f04931c60e0f296277b0b74 OK 2025/03/07 11:16:59 DEBUG : c/non empty space: md5 = 1be6bd3b4a25652410bb5bbbced8c4a6 OK 2025/03/07 11:16:59 INFO : d: Making directory 2025/03/07 11:17:00 INFO : d/e: Making directory 2025/03/07 11:17:02 DEBUG : Added delayed dir = "a", newDst= 2025/03/07 11:17:03 INFO : c: Set directory modification time (using SetModTime) 2025/03/07 11:17:03 DEBUG : Added delayed dir = "c", newDst=c 2025/03/07 11:17:03 DEBUG : a/potato2: Need to transfer - File not found at Destination 2025/03/07 11:17:03 DEBUG : c/non empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/03/07 11:17:03 DEBUG : c/non empty space: Unchanged skipping 2025/03/07 11:17:04 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-filesez1jaqi': Waiting for checks to finish 2025/03/07 11:17:04 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-filesez1jaqi': Waiting for transfers to finish 2025/03/07 11:17:05 DEBUG : a/potato2: md5 = dabaef8e65fbb3b51abea2fd4c171fdb OK 2025/03/07 11:17:05 INFO : a/potato2: Copied (new) 2025/03/07 11:17:05 DEBUG : Waiting for deletions to finish 2025/03/07 11:17:05 INFO : b/potato: Deleted 2025/03/07 11:17:06 INFO : a: Set directory modification time (using DirSetModTime) 2025/03/07 11:17:06 INFO : d/e: Removing directory 2025/03/07 11:17:06 INFO : d: Removing directory 2025/03/07 11:17:07 DEBUG : ka6id8d20d3s5ktapedlphgta8: Rmdir: contains trashed file: "r8sppajuabeak3sbgj2ak8vuf8" 2025/03/07 11:17:07 INFO : b: Removing directory 2025/03/07 11:17:08 DEBUG : 32d8ua6196mc1r7qkfog53rkg0: Rmdir: contains trashed file: "2m507n64kafsi59v9q71r281a4" 2025/03/07 11:17:08 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-filesez1jaqi': deleted 3 directories run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-filesez1jaqi'", Local "Local file system at /tmp/rclone2831462366", Modify Window "1ms" 2025/03/07 11:17:10 DEBUG : 3i9du405pfogq3ncai6pg7ouio: Rmdir: contains trashed file: "982d3pss7t5pn0il16r2foj31s" 2025/03/07 11:17:11 DEBUG : 2bsvlrk2ne1lfitm6tttcu0qt8: Rmdir: contains trashed file: "89l8renevh3mji1c8r1p7qn6tg" --- PASS: TestSyncAfterRemovingAFileAndAddingAFileSubDir (17.29s) === RUN TestSyncAfterRemovingAFileAndAddingAFileSubDirWithErrors run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-filesez1jaqi'", Local "Local file system at /tmp/rclone2831462366", Modify Window "1ms" 2025/03/07 11:17:14 DEBUG : b/potato: md5 = dc028564dc2cfd75ca59d6218da8db5b OK 2025/03/07 11:17:17 DEBUG : c/non empty space: md5 = 556635254459f92c02418c34c662cec8 OK 2025/03/07 11:17:17 INFO : d: Making directory 2025/03/07 11:17:18 DEBUG : Added delayed dir = "a", newDst= 2025/03/07 11:17:19 INFO : c: Set directory modification time (using SetModTime) 2025/03/07 11:17:19 DEBUG : Added delayed dir = "c", newDst=c 2025/03/07 11:17:19 DEBUG : a/potato2: Need to transfer - File not found at Destination 2025/03/07 11:17:19 DEBUG : c/non empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/03/07 11:17:19 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-filesez1jaqi': Waiting for checks to finish 2025/03/07 11:17:19 DEBUG : c/non empty space: Unchanged skipping 2025/03/07 11:17:19 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-filesez1jaqi': Waiting for transfers to finish 2025/03/07 11:17:21 DEBUG : a/potato2: md5 = 20def7a99da1fd9af695264f8ac77c0d OK 2025/03/07 11:17:21 INFO : a/potato2: Copied (new) 2025/03/07 11:17:21 ERROR : Encrypted drive 'TestCryptDrive:rclone-test-filesez1jaqi': not deleting files as there were IO errors 2025/03/07 11:17:21 INFO : a: Set directory modification time (using DirSetModTime) 2025/03/07 11:17:21 ERROR : Encrypted drive 'TestCryptDrive:rclone-test-filesez1jaqi': not deleting directories as there were IO errors run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-filesez1jaqi'", Local "Local file system at /tmp/rclone2831462366", Modify Window "1ms" 2025/03/07 11:17:25 DEBUG : 3i9du405pfogq3ncai6pg7ouio: Rmdir: contains trashed file: "982d3pss7t5pn0il16r2foj31s" 2025/03/07 11:17:26 DEBUG : 32d8ua6196mc1r7qkfog53rkg0: Rmdir: contains trashed file: "2m507n64kafsi59v9q71r281a4" 2025/03/07 11:17:26 DEBUG : 2bsvlrk2ne1lfitm6tttcu0qt8: Rmdir: contains trashed file: "89l8renevh3mji1c8r1p7qn6tg" --- PASS: TestSyncAfterRemovingAFileAndAddingAFileSubDirWithErrors (15.25s) === RUN TestSyncDeleteAfter --- PASS: TestSyncDeleteAfter (0.00s) === RUN TestSyncDeleteDuring run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-filesez1jaqi'", Local "Local file system at /tmp/rclone2831462366", Modify Window "1ms" 2025/03/07 11:17:29 DEBUG : potato: md5 = 244845542a5843c0fcce4a19e74031a6 OK 2025/03/07 11:17:31 DEBUG : empty space: md5 = e5b432ae609a5a29e0bbb9d2de93076c OK 2025/03/07 11:17:31 DEBUG : Waiting for deletions to finish 2025/03/07 11:17:31 DEBUG : potato2: Need to transfer - File not found at Destination 2025/03/07 11:17:31 DEBUG : empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/03/07 11:17:31 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-filesez1jaqi': Waiting for checks to finish 2025/03/07 11:17:31 DEBUG : empty space: Unchanged skipping 2025/03/07 11:17:31 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-filesez1jaqi': Waiting for transfers to finish 2025/03/07 11:17:32 INFO : potato: Deleted 2025/03/07 11:17:32 DEBUG : potato2: md5 = 542894591430dcbf5c213d52660280da OK 2025/03/07 11:17:32 INFO : potato2: Copied (new) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-filesez1jaqi'", Local "Local file system at /tmp/rclone2831462366", Modify Window "1ms" --- PASS: TestSyncDeleteDuring (7.15s) === RUN TestSyncDeleteBefore run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-filesez1jaqi'", Local "Local file system at /tmp/rclone2831462366", Modify Window "1ms" 2025/03/07 11:17:36 DEBUG : potato: md5 = 3ae4db8b108a115d3cb549a0cf5eefbe OK 2025/03/07 11:17:38 DEBUG : empty space: md5 = 607a90092d23eb52de268419d91c534e OK 2025/03/07 11:17:38 DEBUG : Waiting for deletions to finish 2025/03/07 11:17:38 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-filesez1jaqi': Waiting for checks to finish 2025/03/07 11:17:38 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-filesez1jaqi': Waiting for transfers to finish 2025/03/07 11:17:38 INFO : potato: Deleted 2025/03/07 11:17:39 DEBUG : potato2: Need to transfer - File not found at Destination 2025/03/07 11:17:39 DEBUG : empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/03/07 11:17:39 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-filesez1jaqi': Waiting for checks to finish 2025/03/07 11:17:39 DEBUG : empty space: Unchanged skipping 2025/03/07 11:17:39 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-filesez1jaqi': Waiting for transfers to finish 2025/03/07 11:17:40 DEBUG : potato2: md5 = 78b3d281f4ddadf1eefd0974c6cbf651 OK 2025/03/07 11:17:40 INFO : potato2: Copied (new) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-filesez1jaqi'", Local "Local file system at /tmp/rclone2831462366", Modify Window "1ms" --- PASS: TestSyncDeleteBefore (7.41s) === RUN TestCopyDeleteBefore run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-filesez1jaqi'", Local "Local file system at /tmp/rclone2831462366", Modify Window "1ms" 2025/03/07 11:17:43 DEBUG : potato: md5 = d2ad7ff6c6dc737cb04351e87e513a43 OK 2025/03/07 11:17:44 DEBUG : potato2: Need to transfer - File not found at Destination 2025/03/07 11:17:44 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-filesez1jaqi': Waiting for checks to finish 2025/03/07 11:17:44 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-filesez1jaqi': Waiting for transfers to finish 2025/03/07 11:17:45 DEBUG : potato2: md5 = 900e0e0d7c0d9371d13d1e1f06a12bdf OK 2025/03/07 11:17:45 INFO : potato2: Copied (new) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-filesez1jaqi'", Local "Local file system at /tmp/rclone2831462366", Modify Window "1ms" --- PASS: TestCopyDeleteBefore (5.43s) === RUN TestSyncWithExclude run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-filesez1jaqi'", Local "Local file system at /tmp/rclone2831462366", Modify Window "1ms" 2025/03/07 11:17:49 DEBUG : potato2: md5 = 08cdca8acbca15ff426d7896c2ce8172 OK 2025/03/07 11:17:51 DEBUG : empty space: md5 = a2b7e1f98537eddaa3d842e4c54d5997 OK 2025/03/07 11:17:51 DEBUG : enormous: Excluded (Size Filter) 2025/03/07 11:17:51 DEBUG : enormous: Excluded 2025/03/07 11:17:51 DEBUG : potato2: Excluded (Size Filter) 2025/03/07 11:17:51 DEBUG : potato2: Excluded 2025/03/07 11:17:51 DEBUG : potato2: Excluded (Size Filter) 2025/03/07 11:17:51 DEBUG : potato2: Excluded 2025/03/07 11:17:51 DEBUG : empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/03/07 11:17:51 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-filesez1jaqi': Waiting for checks to finish 2025/03/07 11:17:51 DEBUG : empty space: Unchanged skipping 2025/03/07 11:17:51 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-filesez1jaqi': Waiting for transfers to finish 2025/03/07 11:17:51 DEBUG : Waiting for deletions to finish 2025/03/07 11:17:51 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-filesez1jaqi'", Local "Local file system at /tmp/rclone2831462366", Modify Window "1ms" 2025/03/07 11:17:52 DEBUG : enormous: Excluded (Size Filter) 2025/03/07 11:17:52 DEBUG : enormous: Excluded 2025/03/07 11:17:52 DEBUG : potato2: Excluded (Size Filter) 2025/03/07 11:17:52 DEBUG : potato2: Excluded 2025/03/07 11:17:52 DEBUG : potato2: Excluded (Size Filter) 2025/03/07 11:17:52 DEBUG : potato2: Excluded 2025/03/07 11:17:52 DEBUG : Local file system at /tmp/rclone2831462366: Waiting for checks to finish 2025/03/07 11:17:52 DEBUG : empty space: Size and modification time the same (differ by 456.789µs, within tolerance 1ms) 2025/03/07 11:17:52 DEBUG : empty space: Unchanged skipping 2025/03/07 11:17:52 DEBUG : Local file system at /tmp/rclone2831462366: Waiting for transfers to finish 2025/03/07 11:17:52 DEBUG : Waiting for deletions to finish 2025/03/07 11:17:52 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-filesez1jaqi'", Local "Local file system at /tmp/rclone2831462366", Modify Window "1ms" --- PASS: TestSyncWithExclude (6.51s) === RUN TestSyncWithExcludeAndDeleteExcluded run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-filesez1jaqi'", Local "Local file system at /tmp/rclone2831462366", Modify Window "1ms" 2025/03/07 11:17:55 DEBUG : potato2: md5 = 7be1eb032ffccd7bc800b9486c96fd0a OK 2025/03/07 11:17:57 DEBUG : empty space: md5 = 0bb1f5a01c4f9b136bf12345b876f666 OK 2025/03/07 11:17:58 DEBUG : enormous: md5 = 78417ea7892d6efc1e5ff1aea2499577 OK 2025/03/07 11:17:58 DEBUG : enormous: Excluded (Size Filter) 2025/03/07 11:17:58 DEBUG : enormous: Excluded 2025/03/07 11:17:58 DEBUG : potato2: Excluded (Size Filter) 2025/03/07 11:17:58 DEBUG : potato2: Excluded 2025/03/07 11:17:59 DEBUG : empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/03/07 11:17:59 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-filesez1jaqi': Waiting for checks to finish 2025/03/07 11:17:59 DEBUG : empty space: Unchanged skipping 2025/03/07 11:17:59 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-filesez1jaqi': Waiting for transfers to finish 2025/03/07 11:17:59 DEBUG : Waiting for deletions to finish 2025/03/07 11:17:59 INFO : potato2: Deleted 2025/03/07 11:17:59 INFO : enormous: Deleted 2025/03/07 11:17:59 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-filesez1jaqi'", Local "Local file system at /tmp/rclone2831462366", Modify Window "1ms" 2025/03/07 11:18:00 DEBUG : Local file system at /tmp/rclone2831462366: Waiting for checks to finish 2025/03/07 11:18:00 DEBUG : empty space: Size and modification time the same (differ by 456.789µs, within tolerance 1ms) 2025/03/07 11:18:00 DEBUG : empty space: Unchanged skipping 2025/03/07 11:18:00 DEBUG : Local file system at /tmp/rclone2831462366: Waiting for transfers to finish 2025/03/07 11:18:00 DEBUG : Waiting for deletions to finish 2025/03/07 11:18:00 INFO : potato2: Deleted 2025/03/07 11:18:00 INFO : enormous: Deleted 2025/03/07 11:18:00 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-filesez1jaqi'", Local "Local file system at /tmp/rclone2831462366", Modify Window "1ms" --- PASS: TestSyncWithExcludeAndDeleteExcluded (7.76s) === RUN TestSyncWithUpdateOlder run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-filesez1jaqi'", Local "Local file system at /tmp/rclone2831462366", Modify Window "1ms" 2025/03/07 11:18:03 DEBUG : one: md5 = 0a5e4e4c107ca2362d2362a067b9e209 OK 2025/03/07 11:18:05 DEBUG : two: md5 = b0ebaf58ea40af959183dfac8bc42003 OK 2025/03/07 11:18:06 DEBUG : three: md5 = 5fcc030da9662866ea6ba4b21ff49846 OK 2025/03/07 11:18:07 DEBUG : four: md5 = 1cbdb6950fc8a25c0d2fddf5ab9c8ee4 OK 2025/03/07 11:18:08 DEBUG : five: Need to transfer - File not found at Destination 2025/03/07 11:18:08 DEBUG : four: Sizes differ (src 4 vs dst 8) 2025/03/07 11:18:08 DEBUG : three: Sizes identical 2025/03/07 11:18:08 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-filesez1jaqi': Waiting for checks to finish 2025/03/07 11:18:08 DEBUG : one: Destination is newer than source, skipping 2025/03/07 11:18:08 DEBUG : four: Destination mod time is within 1s of source but files differ, transferring 2025/03/07 11:18:08 DEBUG : three: Destination mod time is within 1s of source and files identical, skipping 2025/03/07 11:18:08 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-filesez1jaqi': Waiting for transfers to finish 2025/03/07 11:18:09 DEBUG : two: md5 = 551fe4da4bbafb5859912911be7ac611 OK 2025/03/07 11:18:09 INFO : two: Copied (replaced existing) 2025/03/07 11:18:09 DEBUG : four: md5 = 7c0c38ff2b27f8ee363734874fa8678e OK 2025/03/07 11:18:09 INFO : four: Copied (replaced existing) 2025/03/07 11:18:09 DEBUG : five: md5 = e2fd03c886d26707001ca0d109e9a7a9 OK 2025/03/07 11:18:09 INFO : five: Copied (new) 2025/03/07 11:18:09 DEBUG : Waiting for deletions to finish sync_test.go:1449: Skip test with --checksum as no hashes supported --- PASS: TestSyncWithUpdateOlder (10.72s) === 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-filesez1jaqi'", Local "Local file system at /tmp/rclone2831462366", Modify Window "1ms" sync_test.go:1538: Can track renames: false 2025/03/07 11:18:12 ERROR : Encrypted drive 'TestCryptDrive:rclone-test-filesez1jaqi': Ignoring --track-renames as the source and destination do not have a common hash 2025/03/07 11:18:13 DEBUG : potato: Need to transfer - File not found at Destination 2025/03/07 11:18:13 DEBUG : yam: Need to transfer - File not found at Destination 2025/03/07 11:18:13 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-filesez1jaqi': Waiting for checks to finish 2025/03/07 11:18:13 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-filesez1jaqi': Waiting for transfers to finish 2025/03/07 11:18:14 DEBUG : yam: md5 = 96dc1cd1cf42c3ff6f9d8ddba707ec1b OK 2025/03/07 11:18:14 INFO : yam: Copied (new) 2025/03/07 11:18:14 DEBUG : potato: md5 = 8d69fa64f87071093cba052c7580abc0 OK 2025/03/07 11:18:14 INFO : potato: Copied (new) 2025/03/07 11:18:14 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-filesez1jaqi'", Local "Local file system at /tmp/rclone2831462366", Modify Window "1ms" 2025/03/07 11:18:14 ERROR : Encrypted drive 'TestCryptDrive:rclone-test-filesez1jaqi': Ignoring --track-renames as the source and destination do not have a common hash 2025/03/07 11:18:15 DEBUG : yaml: Need to transfer - File not found at Destination 2025/03/07 11:18:15 DEBUG : potato: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/03/07 11:18:15 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-filesez1jaqi': Waiting for checks to finish 2025/03/07 11:18:15 DEBUG : potato: Unchanged skipping 2025/03/07 11:18:15 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-filesez1jaqi': Waiting for transfers to finish 2025/03/07 11:18:16 DEBUG : yaml: md5 = c84bd54ee9206938e13431a203d3f8ad OK 2025/03/07 11:18:16 INFO : yaml: Copied (new) 2025/03/07 11:18:16 DEBUG : Waiting for deletions to finish 2025/03/07 11:18:17 INFO : yam: Deleted run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-filesez1jaqi'", Local "Local file system at /tmp/rclone2831462366", Modify Window "1ms" --- PASS: TestSyncWithTrackRenames (6.81s) === RUN TestParseRenamesStrategyModtime --- PASS: TestParseRenamesStrategyModtime (0.00s) === RUN TestRenamesStrategyModtime --- PASS: TestRenamesStrategyModtime (0.00s) === RUN TestSyncWithTrackRenamesStrategyModtime run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-filesez1jaqi'", Local "Local file system at /tmp/rclone2831462366", Modify Window "1ms" sync_test.go:1610: Can track renames: true 2025/03/07 11:18:20 INFO : Encrypted drive 'TestCryptDrive:rclone-test-filesez1jaqi': Making map for --track-renames 2025/03/07 11:18:20 INFO : Encrypted drive 'TestCryptDrive:rclone-test-filesez1jaqi': Finished making map for --track-renames 2025/03/07 11:18:20 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-filesez1jaqi': Waiting for checks to finish 2025/03/07 11:18:20 DEBUG : potato: Need to transfer - No matching file found at Destination 2025/03/07 11:18:20 DEBUG : yam: Need to transfer - No matching file found at Destination 2025/03/07 11:18:20 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-filesez1jaqi': Waiting for renames to finish 2025/03/07 11:18:20 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-filesez1jaqi': Waiting for transfers to finish 2025/03/07 11:18:21 DEBUG : yam: md5 = e06d94e5306bbc0317fa74b3bc88a5e7 OK 2025/03/07 11:18:21 INFO : yam: Copied (new) 2025/03/07 11:18:21 DEBUG : potato: md5 = ce9b11806c528c98df91ab6ae784dd66 OK 2025/03/07 11:18:21 INFO : potato: Copied (new) 2025/03/07 11:18:21 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-filesez1jaqi'", Local "Local file system at /tmp/rclone2831462366", Modify Window "1ms" 2025/03/07 11:18:22 INFO : Encrypted drive 'TestCryptDrive:rclone-test-filesez1jaqi': Making map for --track-renames 2025/03/07 11:18:22 DEBUG : potato: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/03/07 11:18:22 INFO : Encrypted drive 'TestCryptDrive:rclone-test-filesez1jaqi': Finished making map for --track-renames 2025/03/07 11:18:22 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-filesez1jaqi': Waiting for checks to finish 2025/03/07 11:18:22 DEBUG : potato: Unchanged skipping 2025/03/07 11:18:22 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-filesez1jaqi': Waiting for renames to finish 2025/03/07 11:18:22 INFO : yam: Moved (server-side) to: yaml 2025/03/07 11:18:22 INFO : yaml: Renamed from "yam" 2025/03/07 11:18:22 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-filesez1jaqi': Waiting for transfers to finish 2025/03/07 11:18:22 DEBUG : Waiting for deletions to finish 2025/03/07 11:18:22 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-filesez1jaqi'", Local "Local file system at /tmp/rclone2831462366", Modify Window "1ms" --- PASS: TestSyncWithTrackRenamesStrategyModtime (5.67s) === RUN TestSyncWithTrackRenamesStrategyLeaf run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-filesez1jaqi'", Local "Local file system at /tmp/rclone2831462366", Modify Window "1ms" sync_test.go:1649: Can track renames: true 2025/03/07 11:18:25 DEBUG : Added delayed dir = "sub", newDst= 2025/03/07 11:18:25 INFO : Encrypted drive 'TestCryptDrive:rclone-test-filesez1jaqi': Making map for --track-renames 2025/03/07 11:18:25 INFO : Encrypted drive 'TestCryptDrive:rclone-test-filesez1jaqi': Finished making map for --track-renames 2025/03/07 11:18:25 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-filesez1jaqi': Waiting for checks to finish 2025/03/07 11:18:25 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-filesez1jaqi': Waiting for renames to finish 2025/03/07 11:18:25 DEBUG : potato: Need to transfer - No matching file found at Destination 2025/03/07 11:18:25 DEBUG : sub/yam: Need to transfer - No matching file found at Destination 2025/03/07 11:18:25 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-filesez1jaqi': Waiting for transfers to finish 2025/03/07 11:18:27 DEBUG : potato: md5 = 55853c497922fd540c5bd8cc20b6be8f OK 2025/03/07 11:18:27 INFO : potato: Copied (new) 2025/03/07 11:18:28 DEBUG : sub/yam: md5 = 63941ede3ac6dac120f9656ecdaa1b5c OK 2025/03/07 11:18:28 INFO : sub/yam: Copied (new) 2025/03/07 11:18:28 DEBUG : Waiting for deletions to finish 2025/03/07 11:18:28 INFO : sub: Set directory modification time (using DirSetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-filesez1jaqi'", Local "Local file system at /tmp/rclone2831462366", Modify Window "1ms" 2025/03/07 11:18:29 DEBUG : potato: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/03/07 11:18:29 DEBUG : potato: Unchanged skipping 2025/03/07 11:18:29 INFO : sub: Set directory modification time (using SetModTime) 2025/03/07 11:18:29 DEBUG : Added delayed dir = "sub", newDst=sub 2025/03/07 11:18:30 INFO : Encrypted drive 'TestCryptDrive:rclone-test-filesez1jaqi': Making map for --track-renames 2025/03/07 11:18:30 INFO : Encrypted drive 'TestCryptDrive:rclone-test-filesez1jaqi': Finished making map for --track-renames 2025/03/07 11:18:30 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-filesez1jaqi': Waiting for checks to finish 2025/03/07 11:18:30 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-filesez1jaqi': Waiting for renames to finish 2025/03/07 11:18:31 INFO : sub/yam: Moved (server-side) to: yam 2025/03/07 11:18:31 INFO : yam: Renamed from "sub/yam" 2025/03/07 11:18:31 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-filesez1jaqi': Waiting for transfers to finish 2025/03/07 11:18:31 DEBUG : Waiting for deletions to finish 2025/03/07 11:18:31 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-filesez1jaqi'", Local "Local file system at /tmp/rclone2831462366", Modify Window "1ms" --- PASS: TestSyncWithTrackRenamesStrategyLeaf (9.53s) === RUN TestServerSideMoveLocal run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-filesez1jaqi'", Local "Local file system at /tmp/rclone2831462366", Modify Window "1ms" 2025/03/07 11:18:34 DEBUG : Creating backend with remote "/tmp/rclone2831462366/dir1" 2025/03/07 11:18:34 DEBUG : Config file has changed externally - reloading 2025/03/07 11:18:34 DEBUG : Creating backend with remote "/tmp/rclone2831462366/dir2" 2025/03/07 11:18:34 DEBUG : Local file system at /tmp/rclone2831462366/dir2: Using server-side directory move 2025/03/07 11:18:34 INFO : Local file system at /tmp/rclone2831462366/dir2: Server side directory move failed - fallback to file moves: can't copy directory - destination already exists 2025/03/07 11:18:34 DEBUG : file1.txt: Need to transfer - File not found at Destination 2025/03/07 11:18:34 DEBUG : Local file system at /tmp/rclone2831462366/dir2: Waiting for checks to finish 2025/03/07 11:18:34 INFO : file1.txt: Moved (server-side) 2025/03/07 11:18:34 DEBUG : Local file system at /tmp/rclone2831462366/dir2: Waiting for transfers to finish --- PASS: TestServerSideMoveLocal (0.45s) === RUN TestMoveWithDeleteEmptySrcDirs run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-filesez1jaqi'", Local "Local file system at /tmp/rclone2831462366", Modify Window "1ms" 2025/03/07 11:18:35 DEBUG : Added delayed dir = "nested", newDst= 2025/03/07 11:18:35 DEBUG : Added delayed dir = "sub dir", newDst= 2025/03/07 11:18:35 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2025/03/07 11:18:35 DEBUG : Added delayed dir = "nested/sub dir", newDst= 2025/03/07 11:18:35 DEBUG : nested/sub dir/file: Need to transfer - File not found at Destination 2025/03/07 11:18:35 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-filesez1jaqi': Waiting for checks to finish 2025/03/07 11:18:35 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-filesez1jaqi': Waiting for transfers to finish 2025/03/07 11:18:37 DEBUG : sub dir/hello world: md5 = 65cad966e5ff1f73e75033b5c0d67701 OK 2025/03/07 11:18:37 INFO : sub dir/hello world: Copied (new) 2025/03/07 11:18:37 INFO : sub dir/hello world: Deleted 2025/03/07 11:18:39 DEBUG : nested/sub dir/file: md5 = ff138a88edea7e26b74713c6a92fe363 OK 2025/03/07 11:18:39 INFO : nested/sub dir/file: Copied (new) 2025/03/07 11:18:39 INFO : nested/sub dir/file: Deleted 2025/03/07 11:18:40 INFO : nested/sub dir: Set directory modification time (using DirSetModTime) 2025/03/07 11:18:40 INFO : nested: Set directory modification time (using DirSetModTime) 2025/03/07 11:18:40 INFO : sub dir: Set directory modification time (using DirSetModTime) 2025/03/07 11:18:40 INFO : sub dir: Removing directory 2025/03/07 11:18:40 INFO : nested/sub dir: Removing directory 2025/03/07 11:18:40 INFO : nested: Removing directory 2025/03/07 11:18:40 DEBUG : Local file system at /tmp/rclone2831462366: deleted 3 directories run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-filesez1jaqi'", Local "Local file system at /tmp/rclone2831462366", Modify Window "1ms" 2025/03/07 11:18:43 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" 2025/03/07 11:18:44 DEBUG : 37qp6d1gohacv723ij3brofbu8/14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "ftp4kuv8se7tqduu6pmmcvjsmk" 2025/03/07 11:18:45 DEBUG : 37qp6d1gohacv723ij3brofbu8: Rmdir: contains trashed file: "14begaa36ih249fgrnfk6nulg0" --- PASS: TestMoveWithDeleteEmptySrcDirs (10.79s) === RUN TestMoveWithoutDeleteEmptySrcDirs run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-filesez1jaqi'", Local "Local file system at /tmp/rclone2831462366", Modify Window "1ms" 2025/03/07 11:18:46 DEBUG : Added delayed dir = "nested", newDst= 2025/03/07 11:18:46 DEBUG : Added delayed dir = "sub dir", newDst= 2025/03/07 11:18:46 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2025/03/07 11:18:46 DEBUG : Added delayed dir = "nested/sub dir", newDst= 2025/03/07 11:18:46 DEBUG : nested/sub dir/file: Need to transfer - File not found at Destination 2025/03/07 11:18:46 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-filesez1jaqi': Waiting for checks to finish 2025/03/07 11:18:46 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-filesez1jaqi': Waiting for transfers to finish 2025/03/07 11:18:48 DEBUG : sub dir/hello world: md5 = 9a98f9afed789818bdb3f9e462fc79f3 OK 2025/03/07 11:18:48 INFO : sub dir/hello world: Copied (new) 2025/03/07 11:18:48 INFO : sub dir/hello world: Deleted 2025/03/07 11:18:50 DEBUG : nested/sub dir/file: md5 = a948e4bc58afaea94784f6562d26f74b OK 2025/03/07 11:18:50 INFO : nested/sub dir/file: Copied (new) 2025/03/07 11:18:50 INFO : nested/sub dir/file: Deleted 2025/03/07 11:18:51 INFO : nested/sub dir: Set directory modification time (using DirSetModTime) 2025/03/07 11:18:52 INFO : nested: Set directory modification time (using DirSetModTime) 2025/03/07 11:18:52 INFO : sub dir: Set directory modification time (using DirSetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-filesez1jaqi'", Local "Local file system at /tmp/rclone2831462366", Modify Window "1ms" 2025/03/07 11:18:54 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" 2025/03/07 11:18:55 DEBUG : 37qp6d1gohacv723ij3brofbu8/14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "ftp4kuv8se7tqduu6pmmcvjsmk" 2025/03/07 11:18:56 DEBUG : 37qp6d1gohacv723ij3brofbu8: Rmdir: contains trashed file: "14begaa36ih249fgrnfk6nulg0" --- PASS: TestMoveWithoutDeleteEmptySrcDirs (11.04s) === RUN TestMoveWithIgnoreExisting run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-filesez1jaqi'", Local "Local file system at /tmp/rclone2831462366", Modify Window "1ms" 2025/03/07 11:18:57 DEBUG : existing: Need to transfer - File not found at Destination 2025/03/07 11:18:57 DEBUG : existing-b: Need to transfer - File not found at Destination 2025/03/07 11:18:57 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-filesez1jaqi': Waiting for checks to finish 2025/03/07 11:18:57 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-filesez1jaqi': Waiting for transfers to finish 2025/03/07 11:18:59 DEBUG : existing: md5 = 4290e2b3c4af0398f973e08558191478 OK 2025/03/07 11:18:59 INFO : existing: Copied (new) 2025/03/07 11:18:59 INFO : existing: Deleted 2025/03/07 11:18:59 DEBUG : existing-b: md5 = 9ffb52bd14e716af2ecdae8b6edef05c OK 2025/03/07 11:18:59 INFO : existing-b: Copied (new) 2025/03/07 11:18:59 INFO : existing-b: Deleted 2025/03/07 11:18:59 DEBUG : existing: Destination exists, skipping 2025/03/07 11:18:59 DEBUG : existing: Not removing source file as destination file exists and --ignore-existing is set 2025/03/07 11:18:59 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-filesez1jaqi': Waiting for checks to finish 2025/03/07 11:18:59 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-filesez1jaqi': Waiting for transfers to finish 2025/03/07 11:18:59 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-filesez1jaqi'", Local "Local file system at /tmp/rclone2831462366", Modify Window "1ms" --- PASS: TestMoveWithIgnoreExisting (5.12s) === RUN TestServerSideMove run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-filesez1jaqi'", Local "Local file system at /tmp/rclone2831462366", Modify Window "1ms" 2025/03/07 11:19:02 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-lizitiz4xemu" 2025/03/07 11:19:02 DEBUG : Creating backend with remote "TestDrive:crypt/ogdq4co7eib7na0r5p5cmv4fr1gmsalh50stgv4t499422e1pup0" 2025/03/07 11:19:04 DEBUG : potato2: md5 = 6ecbe38a6bdfcbff7948c72271ed4eba OK 2025/03/07 11:19:06 DEBUG : empty space: md5 = e5d5fb8bb3c647022df49daa98f9a358 OK 2025/03/07 11:19:07 DEBUG : potato3: md5 = 54008edbf4734e0669e065852e907158 OK sync_test.go:1705: Server side move (if possible) Encrypted drive 'TestCryptDrive:rclone-test-filesez1jaqi' -> Encrypted drive 'TestCryptDrive:rclone-test-lizitiz4xemu' 2025/03/07 11:19:09 DEBUG : empty space: md5 = 69d8eb562966a4761cbed6a39c752513 OK 2025/03/07 11:19:11 DEBUG : potato3: md5 = 0f675e569b44d8e2c4e8a23ff4e7180b OK 2025/03/07 11:19:11 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-lizitiz4xemu': Using server-side directory move 2025/03/07 11:19:11 INFO : Encrypted drive 'TestCryptDrive:rclone-test-lizitiz4xemu': Server side directory move failed - fallback to file moves: can't copy directory - destination already exists 2025/03/07 11:19:11 DEBUG : potato2: Need to transfer - File not found at Destination 2025/03/07 11:19:11 DEBUG : empty space: Size and modification time the same (differ by 0s, within tolerance 1ms) 2025/03/07 11:19:11 DEBUG : empty space: Unchanged skipping 2025/03/07 11:19:11 DEBUG : potato3: Sizes differ (src 68 vs dst 60) 2025/03/07 11:19:11 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-lizitiz4xemu': Waiting for checks to finish 2025/03/07 11:19:12 INFO : empty space: Deleted 2025/03/07 11:19:12 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-lizitiz4xemu': Waiting for transfers to finish 2025/03/07 11:19:12 INFO : potato3: Deleted 2025/03/07 11:19:12 INFO : potato2: Moved (server-side) 2025/03/07 11:19:12 INFO : potato3: Moved (server-side) 2025/03/07 11:19:13 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-nisopeq4jofi" 2025/03/07 11:19:13 DEBUG : Creating backend with remote "TestDrive:crypt/jg1osvbgo1dl41vuhv6n23p4mn90ud6rqgp9044ctl2ed6frroeg" 2025/03/07 11:19:14 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-nisopeq4jofi': Using server-side directory move 2025/03/07 11:19:15 INFO : Encrypted drive 'TestCryptDrive:rclone-test-nisopeq4jofi': Server side directory move succeeded 2025/03/07 11:19:16 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-nisopeq4jofi': Purge remote 2025/03/07 11:19:16 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-lizitiz4xemu': Purge remote 2025/03/07 11:19:16 NOTICE: purge failed: directory not found --- PASS: TestServerSideMove (14.90s) === RUN TestServerSideMoveWithFilter run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-filesez1jaqi'", Local "Local file system at /tmp/rclone2831462366", Modify Window "1ms" 2025/03/07 11:19:17 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-vapafuk1siru" 2025/03/07 11:19:17 DEBUG : Creating backend with remote "TestDrive:crypt/5a6e9aq9n6veo3n2vtlc0i0ikl2ul0f6o0vgpq93hi1b7g3md440" 2025/03/07 11:19:19 DEBUG : potato2: md5 = 5875934fd566798973056c2185166e34 OK 2025/03/07 11:19:21 DEBUG : empty space: md5 = fdce1073a6da9fa296e85f425ffa66a0 OK 2025/03/07 11:19:22 DEBUG : potato3: md5 = 1e6e4ef14302a9d7f5c72fba1785657d OK sync_test.go:1705: Server side move (if possible) Encrypted drive 'TestCryptDrive:rclone-test-filesez1jaqi' -> Encrypted drive 'TestCryptDrive:rclone-test-vapafuk1siru' 2025/03/07 11:19:25 DEBUG : empty space: md5 = e9a6d9f083caf13fe59fd5c5a8b549b2 OK 2025/03/07 11:19:26 DEBUG : potato3: md5 = b944f57af412b26fde301cee1078f169 OK 2025/03/07 11:19:27 DEBUG : empty space: Excluded (Size Filter) 2025/03/07 11:19:27 DEBUG : empty space: Excluded 2025/03/07 11:19:27 DEBUG : empty space: Excluded (Size Filter) 2025/03/07 11:19:27 DEBUG : empty space: Excluded 2025/03/07 11:19:27 DEBUG : potato2: Need to transfer - File not found at Destination 2025/03/07 11:19:27 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vapafuk1siru': Waiting for checks to finish 2025/03/07 11:19:27 DEBUG : potato3: Sizes differ (src 68 vs dst 60) 2025/03/07 11:19:27 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vapafuk1siru': Waiting for transfers to finish 2025/03/07 11:19:27 INFO : potato3: Deleted 2025/03/07 11:19:27 INFO : potato2: Moved (server-side) 2025/03/07 11:19:28 INFO : potato3: Moved (server-side) 2025/03/07 11:19:28 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-fururoc0toho" 2025/03/07 11:19:28 DEBUG : Creating backend with remote "TestDrive:crypt/end90luqcgt8vrqorc8gce41c95ua1upp1pp3p09ul02scjuloe0" 2025/03/07 11:19:30 DEBUG : empty space: Excluded (Size Filter) 2025/03/07 11:19:30 DEBUG : empty space: Excluded 2025/03/07 11:19:30 DEBUG : potato2: Need to transfer - File not found at Destination 2025/03/07 11:19:30 DEBUG : potato3: Need to transfer - File not found at Destination 2025/03/07 11:19:30 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-fururoc0toho': Waiting for checks to finish 2025/03/07 11:19:30 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-fururoc0toho': Waiting for transfers to finish 2025/03/07 11:19:32 INFO : potato2: Moved (server-side) 2025/03/07 11:19:32 INFO : potato3: Moved (server-side) 2025/03/07 11:19:33 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-fururoc0toho': Purge remote 2025/03/07 11:19:33 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vapafuk1siru': Purge remote --- PASS: TestServerSideMoveWithFilter (17.65s) === RUN TestServerSideMoveDeleteEmptySourceDirs run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-filesez1jaqi'", Local "Local file system at /tmp/rclone2831462366", Modify Window "1ms" 2025/03/07 11:19:34 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-masapay1qiqe" 2025/03/07 11:19:34 DEBUG : Creating backend with remote "TestDrive:crypt/t43lva4tg1h52bm2pi84h5gci4jsgds4nvgqu3rq39nnpcodtag0" 2025/03/07 11:19:37 DEBUG : potato2: md5 = 39f4c007eedcf60a47ce75e226476a36 OK 2025/03/07 11:19:38 DEBUG : empty space: md5 = 4df9c2cd8eb6ae746b6fc8253d04d4da OK 2025/03/07 11:19:40 DEBUG : potato3: md5 = 80c51470a998a0396ca996eb18ff06f8 OK 2025/03/07 11:19:40 INFO : tomatoDir: Making directory sync_test.go:1705: Server side move (if possible) Encrypted drive 'TestCryptDrive:rclone-test-filesez1jaqi' -> Encrypted drive 'TestCryptDrive:rclone-test-masapay1qiqe' 2025/03/07 11:19:43 DEBUG : empty space: md5 = 77d1bb632230b21306d3738ea28b731a OK 2025/03/07 11:19:45 DEBUG : potato3: md5 = e9ff0a0adffc5d957a25d26a04e8205f OK 2025/03/07 11:19:45 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-masapay1qiqe': Using server-side directory move 2025/03/07 11:19:45 INFO : Encrypted drive 'TestCryptDrive:rclone-test-masapay1qiqe': Server side directory move failed - fallback to file moves: can't copy directory - destination already exists 2025/03/07 11:19:45 DEBUG : potato2: Need to transfer - File not found at Destination 2025/03/07 11:19:45 DEBUG : Added delayed dir = "tomatoDir", newDst= 2025/03/07 11:19:45 DEBUG : potato3: Sizes differ (src 68 vs dst 60) 2025/03/07 11:19:45 DEBUG : empty space: Size and modification time the same (differ by 0s, within tolerance 1ms) 2025/03/07 11:19:45 DEBUG : empty space: Unchanged skipping 2025/03/07 11:19:45 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-masapay1qiqe': Waiting for checks to finish 2025/03/07 11:19:46 INFO : empty space: Deleted 2025/03/07 11:19:46 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-masapay1qiqe': Waiting for transfers to finish 2025/03/07 11:19:46 INFO : potato3: Deleted 2025/03/07 11:19:46 INFO : potato2: Moved (server-side) 2025/03/07 11:19:46 INFO : potato3: Moved (server-side) 2025/03/07 11:19:46 INFO : tomatoDir: Removing directory 2025/03/07 11:19:47 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-filesez1jaqi': deleted 1 directories 2025/03/07 11:19:48 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-fiwomux6peri" 2025/03/07 11:19:48 DEBUG : Creating backend with remote "TestDrive:crypt/hvj9hvftdb9hftbkb6pgt24uackl973daqafe78s13ljof2d7fk0" 2025/03/07 11:19:49 INFO : tomatoDir: Making directory 2025/03/07 11:19:50 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-fiwomux6peri': Using server-side directory move 2025/03/07 11:19:50 INFO : Encrypted drive 'TestCryptDrive:rclone-test-fiwomux6peri': Server side directory move succeeded 2025/03/07 11:19:52 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-fiwomux6peri': Purge remote 2025/03/07 11:19:52 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-masapay1qiqe': Purge remote 2025/03/07 11:19:52 NOTICE: purge failed: directory not found --- PASS: TestServerSideMoveDeleteEmptySourceDirs (18.48s) === RUN TestServerSideMoveOverlap run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-filesez1jaqi'", Local "Local file system at /tmp/rclone2831462366", Modify Window "1ms" sync_test.go:1910: Skipping test as remote supports DirMove --- SKIP: TestServerSideMoveOverlap (0.47s) === RUN TestSyncOverlap run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-filesez1jaqi'", Local "Local file system at /tmp/rclone2831462366", Modify Window "1ms" 2025/03/07 11:19:53 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-filesez1jaqi/rclone-sync-test" 2025/03/07 11:19:53 DEBUG : Creating backend with remote "TestDrive:crypt/ippqhs6o8n8f9aihb4n2s696sijniukgi2cvh83jmt0ape415uj0/i7355aa0sb89uagn75vfjqr6s3e3e1h2et8in57abn1fe8qfego0" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-filesez1jaqi'", Local "Local file system at /tmp/rclone2831462366", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-filesez1jaqi'", Local "Local file system at /tmp/rclone2831462366", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-filesez1jaqi'", Local "Local file system at /tmp/rclone2831462366", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-filesez1jaqi'", Local "Local file system at /tmp/rclone2831462366", Modify Window "1ms" --- PASS: TestSyncOverlap (3.84s) === RUN TestSyncOverlapWithFilter run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-filesez1jaqi'", Local "Local file system at /tmp/rclone2831462366", Modify Window "1ms" 2025/03/07 11:19:57 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-filesez1jaqi/rclone-sync-test" 2025/03/07 11:19:57 DEBUG : Creating backend with remote "TestDrive:crypt/ippqhs6o8n8f9aihb4n2s696sijniukgi2cvh83jmt0ape415uj0/i7355aa0sb89uagn75vfjqr6s3e3e1h2et8in57abn1fe8qfego0" 2025/03/07 11:20:00 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-filesez1jaqi/rclone-sync-test-include/layer2" 2025/03/07 11:20:00 DEBUG : Creating backend with remote "TestDrive:crypt/ippqhs6o8n8f9aihb4n2s696sijniukgi2cvh83jmt0ape415uj0/khf2vlblvnbf9ftevqm0htmss73hj1j5a7q328e4ohrgs7e2loe0/n01jpl9202nn9ec1rb75h0f1c4" 2025/03/07 11:20:03 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-filesez1jaqi/rclone-sync-test-ignore-file" 2025/03/07 11:20:03 DEBUG : Creating backend with remote "TestDrive:crypt/ippqhs6o8n8f9aihb4n2s696sijniukgi2cvh83jmt0ape415uj0/kmf11jujl9uha3tjganvgpkn45bu778hb5vb5riug1c26b38k7sg" 2025/03/07 11:20:07 DEBUG : rclone-sync-test-ignore-file/.ignore: md5 = b15b76f1b6407415a6f4c170333fa62d OK 2025/03/07 11:20:08 DEBUG : rclone-sync-test-ignore-file: Excluded 2025/03/07 11:20:08 DEBUG : rclone-sync-test: Excluded 2025/03/07 11:20:08 DEBUG : Added delayed dir = "rclone-sync-test-include", newDst= 2025/03/07 11:20:09 DEBUG : rclone-sync-test-include/layer2: Excluded 2025/03/07 11:20:09 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-filesez1jaqi/rclone-sync-test': Waiting for checks to finish 2025/03/07 11:20:09 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-filesez1jaqi/rclone-sync-test': Waiting for transfers to finish 2025/03/07 11:20:09 DEBUG : Waiting for deletions to finish 2025/03/07 11:20:09 INFO : There was nothing to transfer 2025/03/07 11:20:10 DEBUG : rclone-sync-test-ignore-file: Excluded 2025/03/07 11:20:10 DEBUG : rclone-sync-test: Excluded 2025/03/07 11:20:10 DEBUG : rclone-sync-test-include/layer2: Excluded 2025/03/07 11:20:10 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-filesez1jaqi': Waiting for checks to finish 2025/03/07 11:20:10 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-filesez1jaqi': Waiting for transfers to finish 2025/03/07 11:20:10 DEBUG : Waiting for deletions to finish 2025/03/07 11:20:10 INFO : rclone-sync-test-include: Removing directory 2025/03/07 11:20:11 DEBUG : khf2vlblvnbf9ftevqm0htmss73hj1j5a7q328e4ohrgs7e2loe0: Rmdir: contains file: "n01jpl9202nn9ec1rb75h0f1c4" 2025/03/07 11:20:11 DEBUG : rclone-sync-test-include: Failed to Rmdir: directory not empty 2025/03/07 11:20:11 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-filesez1jaqi': failed to delete 1 directories 2025/03/07 11:20:11 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-filesez1jaqi'", Local "Local file system at /tmp/rclone2831462366", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-filesez1jaqi'", Local "Local file system at /tmp/rclone2831462366", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-filesez1jaqi'", Local "Local file system at /tmp/rclone2831462366", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-filesez1jaqi'", Local "Local file system at /tmp/rclone2831462366", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-filesez1jaqi'", Local "Local file system at /tmp/rclone2831462366", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-filesez1jaqi'", Local "Local file system at /tmp/rclone2831462366", Modify Window "1ms" 2025/03/07 11:20:12 DEBUG : rclone-sync-test-ignore-file: Excluded 2025/03/07 11:20:12 DEBUG : rclone-sync-test: Excluded 2025/03/07 11:20:12 DEBUG : Added delayed dir = "rclone-sync-test-include", newDst= 2025/03/07 11:20:12 DEBUG : rclone-sync-test-include/layer2: Excluded 2025/03/07 11:20:12 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-filesez1jaqi/rclone-sync-test-include/layer2': Waiting for checks to finish 2025/03/07 11:20:12 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-filesez1jaqi/rclone-sync-test-include/layer2': Waiting for transfers to finish 2025/03/07 11:20:12 DEBUG : Waiting for deletions to finish 2025/03/07 11:20:12 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-filesez1jaqi'", Local "Local file system at /tmp/rclone2831462366", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-filesez1jaqi'", Local "Local file system at /tmp/rclone2831462366", Modify Window "1ms" 2025/03/07 11:20:13 DEBUG : rclone-sync-test-ignore-file: Excluded 2025/03/07 11:20:14 DEBUG : rclone-sync-test: Excluded 2025/03/07 11:20:14 DEBUG : rclone-sync-test-include/layer2: Excluded 2025/03/07 11:20:14 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-filesez1jaqi': Waiting for checks to finish 2025/03/07 11:20:14 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-filesez1jaqi': Waiting for transfers to finish 2025/03/07 11:20:14 DEBUG : Waiting for deletions to finish 2025/03/07 11:20:14 INFO : rclone-sync-test-include: Removing directory 2025/03/07 11:20:14 DEBUG : khf2vlblvnbf9ftevqm0htmss73hj1j5a7q328e4ohrgs7e2loe0: Rmdir: contains file: "n01jpl9202nn9ec1rb75h0f1c4" 2025/03/07 11:20:14 DEBUG : rclone-sync-test-include: Failed to Rmdir: directory not empty 2025/03/07 11:20:14 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-filesez1jaqi': failed to delete 1 directories 2025/03/07 11:20:14 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-filesez1jaqi'", Local "Local file system at /tmp/rclone2831462366", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-filesez1jaqi'", Local "Local file system at /tmp/rclone2831462366", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-filesez1jaqi'", Local "Local file system at /tmp/rclone2831462366", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-filesez1jaqi'", Local "Local file system at /tmp/rclone2831462366", Modify Window "1ms" 2025/03/07 11:20:15 DEBUG : : Excluded 2025/03/07 11:20:15 DEBUG : rclone-sync-test-ignore-file: Excluded 2025/03/07 11:20:15 DEBUG : rclone-sync-test: Excluded 2025/03/07 11:20:15 DEBUG : Added delayed dir = "rclone-sync-test-include", newDst= 2025/03/07 11:20:16 DEBUG : rclone-sync-test-include/layer2: Excluded 2025/03/07 11:20:16 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-filesez1jaqi/rclone-sync-test-ignore-file': Waiting for checks to finish 2025/03/07 11:20:16 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-filesez1jaqi/rclone-sync-test-ignore-file': Waiting for transfers to finish 2025/03/07 11:20:16 DEBUG : Waiting for deletions to finish 2025/03/07 11:20:16 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-filesez1jaqi'", Local "Local file system at /tmp/rclone2831462366", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-filesez1jaqi'", Local "Local file system at /tmp/rclone2831462366", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-filesez1jaqi'", Local "Local file system at /tmp/rclone2831462366", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-filesez1jaqi'", Local "Local file system at /tmp/rclone2831462366", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-filesez1jaqi'", Local "Local file system at /tmp/rclone2831462366", Modify Window "1ms" 2025/03/07 11:20:18 DEBUG : khf2vlblvnbf9ftevqm0htmss73hj1j5a7q328e4ohrgs7e2loe0: Rmdir: contains trashed file: "n01jpl9202nn9ec1rb75h0f1c4" 2025/03/07 11:20:19 DEBUG : kmf11jujl9uha3tjganvgpkn45bu778hb5vb5riug1c26b38k7sg: Rmdir: contains trashed file: "i0t74httmdlljg425j6tg570d8" --- PASS: TestSyncOverlapWithFilter (30.87s) === RUN TestSyncCompareDest run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-filesez1jaqi'", Local "Local file system at /tmp/rclone2831462366", Modify Window "1ms" 2025/03/07 11:20:28 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-filesez1jaqi/dst" 2025/03/07 11:20:28 DEBUG : Creating backend with remote "TestDrive:crypt/ippqhs6o8n8f9aihb4n2s696sijniukgi2cvh83jmt0ape415uj0/31u3jie661vd5p8j7rtc3hgbh0" 2025/03/07 11:20:30 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-filesez1jaqi/CompareDest" 2025/03/07 11:20:30 DEBUG : Creating backend with remote "TestDrive:crypt/ippqhs6o8n8f9aihb4n2s696sijniukgi2cvh83jmt0ape415uj0/gveqi14airsml4bgu7krj116o8" 2025/03/07 11:20:32 DEBUG : one: Need to transfer - File not found at Destination 2025/03/07 11:20:32 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-filesez1jaqi/dst': Waiting for checks to finish 2025/03/07 11:20:32 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-filesez1jaqi/dst': Waiting for transfers to finish 2025/03/07 11:20:34 DEBUG : one: md5 = fbb82d33d19a62cbbf3c16d051ce00f8 OK 2025/03/07 11:20:34 INFO : one: Copied (new) 2025/03/07 11:20:34 DEBUG : Waiting for deletions to finish 2025/03/07 11:20:35 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-filesez1jaqi/dst': Waiting for checks to finish 2025/03/07 11:20:35 DEBUG : one: Sizes differ (src 5 vs dst 3) 2025/03/07 11:20:35 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-filesez1jaqi/dst': Waiting for transfers to finish 2025/03/07 11:20:36 DEBUG : one: md5 = ba6cf8bc04981bab7de634dc9adc1921 OK 2025/03/07 11:20:36 INFO : one: Copied (replaced existing) 2025/03/07 11:20:36 DEBUG : Waiting for deletions to finish 2025/03/07 11:20:38 DEBUG : dst/one: md5 = 68e55c9bf1513b4329909d9b3f413896 OK 2025/03/07 11:20:40 DEBUG : CompareDest/one: md5 = 95220d0647c9510a1f73cf40672e2c1a OK 2025/03/07 11:20:41 DEBUG : one: Sizes differ (src 5 vs dst 3) 2025/03/07 11:20:41 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-filesez1jaqi/dst': Waiting for checks to finish 2025/03/07 11:20:42 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/03/07 11:20:42 DEBUG : one: Destination found in --compare-dest, skipping 2025/03/07 11:20:42 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-filesez1jaqi/dst': Waiting for transfers to finish 2025/03/07 11:20:42 DEBUG : Waiting for deletions to finish 2025/03/07 11:20:42 INFO : There was nothing to transfer 2025/03/07 11:20:44 DEBUG : CompareDest/two: md5 = 90671ed86347f6bf632d23721fad6a88 OK 2025/03/07 11:20:45 DEBUG : two: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/03/07 11:20:45 DEBUG : two: Destination found in --compare-dest, skipping 2025/03/07 11:20:45 DEBUG : one: Sizes differ (src 5 vs dst 3) 2025/03/07 11:20:45 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-filesez1jaqi/dst': Waiting for checks to finish 2025/03/07 11:20:45 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/03/07 11:20:45 DEBUG : one: Destination found in --compare-dest, skipping 2025/03/07 11:20:45 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-filesez1jaqi/dst': Waiting for transfers to finish 2025/03/07 11:20:45 DEBUG : Waiting for deletions to finish 2025/03/07 11:20:45 INFO : There was nothing to transfer 2025/03/07 11:20:46 DEBUG : two: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/03/07 11:20:46 DEBUG : two: Destination found in --compare-dest, skipping 2025/03/07 11:20:46 DEBUG : one: Sizes differ (src 5 vs dst 3) 2025/03/07 11:20:46 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-filesez1jaqi/dst': Waiting for checks to finish 2025/03/07 11:20:46 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/03/07 11:20:46 DEBUG : one: Destination found in --compare-dest, skipping 2025/03/07 11:20:46 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-filesez1jaqi/dst': Waiting for transfers to finish 2025/03/07 11:20:46 DEBUG : Waiting for deletions to finish 2025/03/07 11:20:46 INFO : There was nothing to transfer sync_test.go:2175: No hash on uploaded file so skipping compare timestamp test 2025/03/07 11:20:48 DEBUG : two: Sizes differ (src 5 vs dst 3) 2025/03/07 11:20:48 DEBUG : two: Need to transfer - File not found at Destination 2025/03/07 11:20:48 DEBUG : one: Sizes differ (src 5 vs dst 3) 2025/03/07 11:20:48 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-filesez1jaqi/dst': Waiting for checks to finish 2025/03/07 11:20:48 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/03/07 11:20:48 DEBUG : one: Destination found in --compare-dest, skipping 2025/03/07 11:20:48 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-filesez1jaqi/dst': Waiting for transfers to finish 2025/03/07 11:20:49 DEBUG : two: md5 = dc7d9e8385cf70eca1e7722ed1315e68 OK 2025/03/07 11:20:49 INFO : two: Copied (new) 2025/03/07 11:20:49 DEBUG : Waiting for deletions to finish 2025/03/07 11:20:52 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k" 2025/03/07 11:20:52 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" 2025/03/07 11:20:53 DEBUG : gveqi14airsml4bgu7krj116o8: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" 2025/03/07 11:20:53 DEBUG : gveqi14airsml4bgu7krj116o8: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k" --- PASS: TestSyncCompareDest (25.53s) === RUN TestSyncMultipleCompareDest run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-filesez1jaqi'", Local "Local file system at /tmp/rclone2831462366", Modify Window "1ms" 2025/03/07 11:20:56 DEBUG : pre-dest1/1: md5 = 62e2c5e7f383472ed08507a269dd00b4 OK 2025/03/07 11:20:58 DEBUG : pre-dest2/2: md5 = 26a6fe8a00f34b5ac0041df888d84093 OK 2025/03/07 11:20:58 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-filesez1jaqi/dest" 2025/03/07 11:20:58 DEBUG : Creating backend with remote "TestDrive:crypt/ippqhs6o8n8f9aihb4n2s696sijniukgi2cvh83jmt0ape415uj0/rg03c1jvnehrrc617i0lnqjddc" 2025/03/07 11:21:00 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-filesez1jaqi/pre-dest1" 2025/03/07 11:21:00 DEBUG : Creating backend with remote "TestDrive:crypt/ippqhs6o8n8f9aihb4n2s696sijniukgi2cvh83jmt0ape415uj0/bbnblvh6k061ssopqrp18kd7gc" 2025/03/07 11:21:01 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-filesez1jaqi/pre-dest2" 2025/03/07 11:21:01 DEBUG : Creating backend with remote "TestDrive:crypt/ippqhs6o8n8f9aihb4n2s696sijniukgi2cvh83jmt0ape415uj0/dgicm1h6b5ejvlltm8eeif0bnk" 2025/03/07 11:21:02 DEBUG : 1: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/03/07 11:21:02 DEBUG : 1: Destination found in --compare-dest, skipping 2025/03/07 11:21:02 DEBUG : 2: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/03/07 11:21:02 DEBUG : 2: Destination found in --compare-dest, skipping 2025/03/07 11:21:03 DEBUG : 3: Need to transfer - File not found at Destination 2025/03/07 11:21:03 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-filesez1jaqi/dest': Waiting for checks to finish 2025/03/07 11:21:03 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-filesez1jaqi/dest': Waiting for transfers to finish 2025/03/07 11:21:05 DEBUG : 3: md5 = d357136c4a5ad743142323944f95e8d4 OK 2025/03/07 11:21:05 INFO : 3: Copied (new) 2025/03/07 11:21:05 DEBUG : Waiting for deletions to finish 2025/03/07 11:21:08 DEBUG : dgicm1h6b5ejvlltm8eeif0bnk: Rmdir: contains trashed file: "1ghu8geql9vrl726n32nrf65bc" 2025/03/07 11:21:09 DEBUG : bbnblvh6k061ssopqrp18kd7gc: Rmdir: contains trashed file: "skbfko3oil7es0lj68ob574sro" 2025/03/07 11:21:09 DEBUG : rg03c1jvnehrrc617i0lnqjddc: Rmdir: contains trashed file: "g072p7hmjchlnj0gibe64c1epg" --- PASS: TestSyncMultipleCompareDest (16.51s) === RUN TestSyncCopyDest run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-filesez1jaqi'", Local "Local file system at /tmp/rclone2831462366", Modify Window "1ms" 2025/03/07 11:21:10 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-filesez1jaqi/dst" 2025/03/07 11:21:10 DEBUG : Creating backend with remote "TestDrive:crypt/ippqhs6o8n8f9aihb4n2s696sijniukgi2cvh83jmt0ape415uj0/31u3jie661vd5p8j7rtc3hgbh0" 2025/03/07 11:21:12 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-filesez1jaqi/CopyDest" 2025/03/07 11:21:12 DEBUG : Creating backend with remote "TestDrive:crypt/ippqhs6o8n8f9aihb4n2s696sijniukgi2cvh83jmt0ape415uj0/d09o6po3f7bm6ce32vdgs8h9ls" 2025/03/07 11:21:14 DEBUG : one: Need to transfer - File not found at Destination 2025/03/07 11:21:14 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-filesez1jaqi/dst': Waiting for checks to finish 2025/03/07 11:21:14 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-filesez1jaqi/dst': Waiting for transfers to finish 2025/03/07 11:21:16 DEBUG : one: md5 = 81c2057c820f30c337dea558c97146dd OK 2025/03/07 11:21:16 INFO : one: Copied (new) 2025/03/07 11:21:16 DEBUG : Waiting for deletions to finish 2025/03/07 11:21:17 DEBUG : one: Sizes differ (src 5 vs dst 3) 2025/03/07 11:21:17 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-filesez1jaqi/dst': Waiting for checks to finish 2025/03/07 11:21:18 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-filesez1jaqi/dst': Waiting for transfers to finish 2025/03/07 11:21:19 DEBUG : one: md5 = 02398c9bd3d91b9265d3c6eae9ffe3b0 OK 2025/03/07 11:21:19 INFO : one: Copied (replaced existing) 2025/03/07 11:21:19 DEBUG : Waiting for deletions to finish 2025/03/07 11:21:21 DEBUG : dst/one: md5 = 128fac616dbba56afec6b790d1e76d9e OK 2025/03/07 11:21:23 DEBUG : CopyDest/one: md5 = fa4a9bcbe173abfce09760e2444ce7b9 OK 2025/03/07 11:21:24 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-filesez1jaqi/BackupDir" 2025/03/07 11:21:24 DEBUG : Creating backend with remote "TestDrive:crypt/ippqhs6o8n8f9aihb4n2s696sijniukgi2cvh83jmt0ape415uj0/s6dbk3lfi7c9kfvo6j7bla9m0g" 2025/03/07 11:21:26 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-filesez1jaqi/dst': Waiting for checks to finish 2025/03/07 11:21:26 DEBUG : one: Sizes differ (src 5 vs dst 3) 2025/03/07 11:21:26 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/03/07 11:21:26 DEBUG : one: Sizes differ (src 5 vs dst 3) 2025/03/07 11:21:28 INFO : one: Moved (server-side) 2025/03/07 11:21:29 INFO : one: Copied (server-side copy) 2025/03/07 11:21:29 DEBUG : one: Destination found in --copy-dest, using server-side copy 2025/03/07 11:21:29 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-filesez1jaqi/dst': Waiting for transfers to finish 2025/03/07 11:21:29 DEBUG : Waiting for deletions to finish 2025/03/07 11:21:31 DEBUG : CopyDest/two: md5 = 0094c2c471204de9e678b60e94044557 OK 2025/03/07 11:21:33 DEBUG : two: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/03/07 11:21:34 INFO : two: Copied (server-side copy) 2025/03/07 11:21:34 DEBUG : two: Destination found in --copy-dest, using server-side copy 2025/03/07 11:21:34 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-filesez1jaqi/dst': Waiting for checks to finish 2025/03/07 11:21:34 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/03/07 11:21:34 DEBUG : one: Unchanged skipping 2025/03/07 11:21:34 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-filesez1jaqi/dst': Waiting for transfers to finish 2025/03/07 11:21:34 DEBUG : Waiting for deletions to finish 2025/03/07 11:21:35 DEBUG : two: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/03/07 11:21:35 DEBUG : two: Unchanged skipping 2025/03/07 11:21:35 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/03/07 11:21:35 DEBUG : one: Unchanged skipping 2025/03/07 11:21:35 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-filesez1jaqi/dst': Waiting for checks to finish 2025/03/07 11:21:35 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-filesez1jaqi/dst': Waiting for transfers to finish 2025/03/07 11:21:35 DEBUG : Waiting for deletions to finish 2025/03/07 11:21:35 INFO : There was nothing to transfer 2025/03/07 11:21:36 DEBUG : CopyDest/three: md5 = 6ca7fde0c227ea2e0186683818e7c74e OK 2025/03/07 11:21:38 DEBUG : three: Sizes differ (src 7 vs dst 5) 2025/03/07 11:21:38 DEBUG : three: Destination not found in --copy-dest 2025/03/07 11:21:38 DEBUG : three: Need to transfer - File not found at Destination 2025/03/07 11:21:38 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/03/07 11:21:38 DEBUG : two: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/03/07 11:21:38 DEBUG : one: Unchanged skipping 2025/03/07 11:21:38 DEBUG : two: Unchanged skipping 2025/03/07 11:21:38 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-filesez1jaqi/dst': Waiting for checks to finish 2025/03/07 11:21:38 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-filesez1jaqi/dst': Waiting for transfers to finish 2025/03/07 11:21:39 DEBUG : three: md5 = 013611d5c62584a5d6052fdaa2c96234 OK 2025/03/07 11:21:39 INFO : three: Copied (new) 2025/03/07 11:21:39 DEBUG : Waiting for deletions to finish 2025/03/07 11:21:43 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "b6jdmn2b1adrhc8vikh7edr9os" 2025/03/07 11:21:43 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k" 2025/03/07 11:21:43 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" 2025/03/07 11:21:44 DEBUG : d09o6po3f7bm6ce32vdgs8h9ls: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k" 2025/03/07 11:21:44 DEBUG : d09o6po3f7bm6ce32vdgs8h9ls: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" 2025/03/07 11:21:44 DEBUG : d09o6po3f7bm6ce32vdgs8h9ls: Rmdir: contains trashed file: "b6jdmn2b1adrhc8vikh7edr9os" 2025/03/07 11:21:45 DEBUG : s6dbk3lfi7c9kfvo6j7bla9m0g: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" --- PASS: TestSyncCopyDest (35.25s) === RUN TestSyncBackupDir run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-filesez1jaqi'", Local "Local file system at /tmp/rclone2831462366", Modify Window "1ms" 2025/03/07 11:21:48 DEBUG : dst/one: md5 = df2418966c88adc0f2c40af65facdd31 OK 2025/03/07 11:21:49 DEBUG : dst/two: md5 = 7ca8438c4d8678dafb94b5bb7c49a64d OK 2025/03/07 11:21:50 DEBUG : dst/three.txt: md5 = 70000c7588715f3529b1d4918098e3e8 OK 2025/03/07 11:21:51 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-filesez1jaqi/dst" 2025/03/07 11:21:51 DEBUG : Creating backend with remote "TestDrive:crypt/ippqhs6o8n8f9aihb4n2s696sijniukgi2cvh83jmt0ape415uj0/31u3jie661vd5p8j7rtc3hgbh0" 2025/03/07 11:21:52 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-filesez1jaqi/backup" 2025/03/07 11:21:52 DEBUG : Creating backend with remote "TestDrive:crypt/ippqhs6o8n8f9aihb4n2s696sijniukgi2cvh83jmt0ape415uj0/1nrff024r7pq65ecp72fc28jb0" 2025/03/07 11:21:54 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-filesez1jaqi/dst': Waiting for checks to finish 2025/03/07 11:21:54 DEBUG : one: Sizes differ (src 4 vs dst 3) 2025/03/07 11:21:54 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/03/07 11:21:54 DEBUG : two: Unchanged skipping 2025/03/07 11:21:55 INFO : one: Moved (server-side) 2025/03/07 11:21:55 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-filesez1jaqi/dst': Waiting for transfers to finish 2025/03/07 11:21:56 DEBUG : one: md5 = 67e96bd564470098200af15cf5073768 OK 2025/03/07 11:21:56 INFO : one: Copied (new) 2025/03/07 11:21:56 DEBUG : Waiting for deletions to finish 2025/03/07 11:21:57 INFO : three.txt: Moved (server-side) 2025/03/07 11:21:57 INFO : three.txt: Moved into backup dir 2025/03/07 11:21:59 DEBUG : dst/three.txt: md5 = 79e351852acd67a8382e1d0be655b47f OK 2025/03/07 11:22:00 DEBUG : one: Sizes differ (src 5 vs dst 4) 2025/03/07 11:22:00 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/03/07 11:22:00 DEBUG : two: Unchanged skipping 2025/03/07 11:22:00 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-filesez1jaqi/dst': Waiting for checks to finish 2025/03/07 11:22:01 INFO : one: Deleted 2025/03/07 11:22:01 INFO : one: Moved (server-side) 2025/03/07 11:22:01 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-filesez1jaqi/dst': Waiting for transfers to finish 2025/03/07 11:22:03 DEBUG : one: md5 = 023447cd89f8273726985a4a15edaace OK 2025/03/07 11:22:03 INFO : one: Copied (new) 2025/03/07 11:22:03 DEBUG : Waiting for deletions to finish 2025/03/07 11:22:03 INFO : three.txt: Deleted 2025/03/07 11:22:04 INFO : three.txt: Moved (server-side) 2025/03/07 11:22:04 INFO : three.txt: Moved into backup dir 2025/03/07 11:22:07 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" 2025/03/07 11:22:07 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k" 2025/03/07 11:22:08 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "tr2hj63d80ftlmvm6a952snjcc" 2025/03/07 11:22:08 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" 2025/03/07 11:22:08 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" 2025/03/07 11:22:08 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "tr2hj63d80ftlmvm6a952snjcc" --- PASS: TestSyncBackupDir (23.01s) === RUN TestSyncBackupDirWithSuffix run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-filesez1jaqi'", Local "Local file system at /tmp/rclone2831462366", Modify Window "1ms" 2025/03/07 11:22:11 DEBUG : dst/one: md5 = a0ad9f00fd2a889f2fb845d66e270932 OK 2025/03/07 11:22:12 DEBUG : dst/two: md5 = a16b9c6889a9aa0ae1baac5381e710a8 OK 2025/03/07 11:22:14 DEBUG : dst/three.txt: md5 = 89112fe04ee35c88d19df47117040195 OK 2025/03/07 11:22:14 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-filesez1jaqi/dst" 2025/03/07 11:22:14 DEBUG : Creating backend with remote "TestDrive:crypt/ippqhs6o8n8f9aihb4n2s696sijniukgi2cvh83jmt0ape415uj0/31u3jie661vd5p8j7rtc3hgbh0" 2025/03/07 11:22:15 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-filesez1jaqi/backup" 2025/03/07 11:22:15 DEBUG : Creating backend with remote "TestDrive:crypt/ippqhs6o8n8f9aihb4n2s696sijniukgi2cvh83jmt0ape415uj0/1nrff024r7pq65ecp72fc28jb0" 2025/03/07 11:22:17 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-filesez1jaqi/dst': Waiting for checks to finish 2025/03/07 11:22:17 DEBUG : one: Sizes differ (src 4 vs dst 3) 2025/03/07 11:22:17 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/03/07 11:22:17 DEBUG : two: Unchanged skipping 2025/03/07 11:22:19 INFO : one: Moved (server-side) to: one.bak 2025/03/07 11:22:19 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-filesez1jaqi/dst': Waiting for transfers to finish 2025/03/07 11:22:20 DEBUG : one: md5 = 61ddcca08ce5bb00a26607fa9a83124b OK 2025/03/07 11:22:20 INFO : one: Copied (new) 2025/03/07 11:22:20 DEBUG : Waiting for deletions to finish 2025/03/07 11:22:21 INFO : three.txt: Moved (server-side) to: three.txt.bak 2025/03/07 11:22:21 INFO : three.txt: Moved into backup dir 2025/03/07 11:22:23 DEBUG : dst/three.txt: md5 = 953bbb8a378b9115db5569390b2c0b6e OK 2025/03/07 11:22:24 DEBUG : one: Sizes differ (src 5 vs dst 4) 2025/03/07 11:22:24 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-filesez1jaqi/dst': Waiting for checks to finish 2025/03/07 11:22:24 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/03/07 11:22:24 DEBUG : two: Unchanged skipping 2025/03/07 11:22:24 INFO : one.bak: Deleted 2025/03/07 11:22:25 INFO : one: Moved (server-side) to: one.bak 2025/03/07 11:22:25 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-filesez1jaqi/dst': Waiting for transfers to finish 2025/03/07 11:22:26 DEBUG : one: md5 = 7540945fd51d4810a71821902f5376d7 OK 2025/03/07 11:22:26 INFO : one: Copied (new) 2025/03/07 11:22:26 DEBUG : Waiting for deletions to finish 2025/03/07 11:22:27 INFO : three.txt.bak: Deleted 2025/03/07 11:22:28 INFO : three.txt: Moved (server-side) to: three.txt.bak 2025/03/07 11:22:28 INFO : three.txt: Moved into backup dir 2025/03/07 11:22:31 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" 2025/03/07 11:22:31 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k" 2025/03/07 11:22:32 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "qltcak2uaegtmcoa8vijdppbp8" 2025/03/07 11:22:32 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "sk91qgsqfn0r271r2ehsaoc20c" 2025/03/07 11:22:32 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "qltcak2uaegtmcoa8vijdppbp8" 2025/03/07 11:22:32 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "sk91qgsqfn0r271r2ehsaoc20c" --- PASS: TestSyncBackupDirWithSuffix (23.87s) === RUN TestSyncBackupDirWithSuffixKeepExtension run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-filesez1jaqi'", Local "Local file system at /tmp/rclone2831462366", Modify Window "1ms" 2025/03/07 11:22:35 DEBUG : dst/one: md5 = c4ec02dd83e7a908e80e9950b9db0aeb OK 2025/03/07 11:22:36 DEBUG : dst/two: md5 = d92edb290676b7d10dae67232d571475 OK 2025/03/07 11:22:38 DEBUG : dst/three.txt: md5 = 6f60063fa520686e7878d81c312cb7a6 OK 2025/03/07 11:22:38 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-filesez1jaqi/dst" 2025/03/07 11:22:38 DEBUG : Creating backend with remote "TestDrive:crypt/ippqhs6o8n8f9aihb4n2s696sijniukgi2cvh83jmt0ape415uj0/31u3jie661vd5p8j7rtc3hgbh0" 2025/03/07 11:22:39 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-filesez1jaqi/backup" 2025/03/07 11:22:39 DEBUG : Creating backend with remote "TestDrive:crypt/ippqhs6o8n8f9aihb4n2s696sijniukgi2cvh83jmt0ape415uj0/1nrff024r7pq65ecp72fc28jb0" 2025/03/07 11:22:41 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-filesez1jaqi/dst': Waiting for checks to finish 2025/03/07 11:22:41 DEBUG : one: Sizes differ (src 4 vs dst 3) 2025/03/07 11:22:41 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/03/07 11:22:41 DEBUG : two: Unchanged skipping 2025/03/07 11:22:42 INFO : one: Moved (server-side) to: one-2019-01-01 2025/03/07 11:22:42 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-filesez1jaqi/dst': Waiting for transfers to finish 2025/03/07 11:22:44 DEBUG : one: md5 = 4c6520d18ca1df1073402db19100714c OK 2025/03/07 11:22:44 INFO : one: Copied (new) 2025/03/07 11:22:44 DEBUG : Waiting for deletions to finish 2025/03/07 11:22:45 INFO : three.txt: Moved (server-side) to: three-2019-01-01.txt 2025/03/07 11:22:45 INFO : three.txt: Moved into backup dir 2025/03/07 11:22:47 DEBUG : dst/three.txt: md5 = 28ee0b0830af5985bd69fb0157035943 OK 2025/03/07 11:22:47 DEBUG : one: Sizes differ (src 5 vs dst 4) 2025/03/07 11:22:47 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/03/07 11:22:47 DEBUG : two: Unchanged skipping 2025/03/07 11:22:47 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-filesez1jaqi/dst': Waiting for checks to finish 2025/03/07 11:22:48 INFO : one-2019-01-01: Deleted 2025/03/07 11:22:49 INFO : one: Moved (server-side) to: one-2019-01-01 2025/03/07 11:22:49 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-filesez1jaqi/dst': Waiting for transfers to finish 2025/03/07 11:22:50 DEBUG : one: md5 = c92c66223a42b6e4bb2b55eac3b4de84 OK 2025/03/07 11:22:50 INFO : one: Copied (new) 2025/03/07 11:22:50 DEBUG : Waiting for deletions to finish 2025/03/07 11:22:51 INFO : three-2019-01-01.txt: Deleted 2025/03/07 11:22:51 INFO : three.txt: Moved (server-side) to: three-2019-01-01.txt 2025/03/07 11:22:51 INFO : three.txt: Moved into backup dir 2025/03/07 11:22:55 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" 2025/03/07 11:22:55 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k" 2025/03/07 11:22:56 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "jcjl1bv3ep0v8kt35lqql1co90" 2025/03/07 11:22:56 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "qtq2f6qq4lgpsmj88vb7147qje3prudmtfdtr2342fth58vo9a50" 2025/03/07 11:22:56 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "jcjl1bv3ep0v8kt35lqql1co90" 2025/03/07 11:22:56 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "qtq2f6qq4lgpsmj88vb7147qje3prudmtfdtr2342fth58vo9a50" --- PASS: TestSyncBackupDirWithSuffixKeepExtension (23.93s) === RUN TestSyncBackupDirSuffixOnly run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-filesez1jaqi'", Local "Local file system at /tmp/rclone2831462366", Modify Window "1ms" 2025/03/07 11:22:58 DEBUG : dst/one: md5 = 7738b0ad4e335f794d81cc860cd7bb6c OK 2025/03/07 11:23:00 DEBUG : dst/two: md5 = 469190525f8a3f781e17ceda4905e1d8 OK 2025/03/07 11:23:01 DEBUG : dst/three.txt: md5 = 7fc0f3b71bdff62e2e5d0482fd1be38d OK 2025/03/07 11:23:02 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-filesez1jaqi/dst" 2025/03/07 11:23:02 DEBUG : Creating backend with remote "TestDrive:crypt/ippqhs6o8n8f9aihb4n2s696sijniukgi2cvh83jmt0ape415uj0/31u3jie661vd5p8j7rtc3hgbh0" 2025/03/07 11:23:03 DEBUG : one: Sizes differ (src 4 vs dst 3) 2025/03/07 11:23:03 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/03/07 11:23:03 DEBUG : two: Unchanged skipping 2025/03/07 11:23:03 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-filesez1jaqi/dst': Waiting for checks to finish 2025/03/07 11:23:04 INFO : one: Moved (server-side) to: one.bak 2025/03/07 11:23:04 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-filesez1jaqi/dst': Waiting for transfers to finish 2025/03/07 11:23:05 DEBUG : one: md5 = 8b688f75254368974bf821f33ef7a4e2 OK 2025/03/07 11:23:05 INFO : one: Copied (new) 2025/03/07 11:23:05 DEBUG : Waiting for deletions to finish 2025/03/07 11:23:06 INFO : three.txt: Moved (server-side) to: three.txt.bak 2025/03/07 11:23:06 INFO : three.txt: Moved into backup dir 2025/03/07 11:23:08 DEBUG : dst/three.txt: md5 = 6ead9d16d44e37b3c2e61c6139d3fd4c OK 2025/03/07 11:23:09 DEBUG : one.bak: Excluded (Path Filter) 2025/03/07 11:23:09 DEBUG : one.bak: Excluded 2025/03/07 11:23:09 DEBUG : three.txt.bak: Excluded (Path Filter) 2025/03/07 11:23:09 DEBUG : three.txt.bak: Excluded 2025/03/07 11:23:09 DEBUG : one: Sizes differ (src 5 vs dst 4) 2025/03/07 11:23:09 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/03/07 11:23:09 DEBUG : two: Unchanged skipping 2025/03/07 11:23:09 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-filesez1jaqi/dst': Waiting for checks to finish 2025/03/07 11:23:09 INFO : one.bak: Deleted 2025/03/07 11:23:10 INFO : one: Moved (server-side) to: one.bak 2025/03/07 11:23:10 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-filesez1jaqi/dst': Waiting for transfers to finish 2025/03/07 11:23:11 DEBUG : one: md5 = e445ccf4bc24579c3f335abedfaa1d2e OK 2025/03/07 11:23:11 INFO : one: Copied (new) 2025/03/07 11:23:11 DEBUG : Waiting for deletions to finish 2025/03/07 11:23:12 INFO : three.txt.bak: Deleted 2025/03/07 11:23:13 INFO : three.txt: Moved (server-side) to: three.txt.bak 2025/03/07 11:23:13 INFO : three.txt: Moved into backup dir 2025/03/07 11:23:16 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" 2025/03/07 11:23:16 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "qltcak2uaegtmcoa8vijdppbp8" 2025/03/07 11:23:16 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "sk91qgsqfn0r271r2ehsaoc20c" 2025/03/07 11:23:16 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "qltcak2uaegtmcoa8vijdppbp8" 2025/03/07 11:23:16 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "sk91qgsqfn0r271r2ehsaoc20c" 2025/03/07 11:23:16 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k" --- PASS: TestSyncBackupDirSuffixOnly (20.17s) === RUN TestSyncSuffix run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-filesez1jaqi'", Local "Local file system at /tmp/rclone2831462366", Modify Window "1ms" 2025/03/07 11:23:19 DEBUG : dst/one: md5 = bbd5fd1d2ee2dae4642485e188ed301b OK 2025/03/07 11:23:20 DEBUG : dst/two: md5 = 3877d096252d2e64866f9101c1605d93 OK 2025/03/07 11:23:21 DEBUG : dst/three.txt: md5 = cdec0a5f4b21863410ef50d755900a1e OK 2025/03/07 11:23:22 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-filesez1jaqi/dst" 2025/03/07 11:23:22 DEBUG : Creating backend with remote "TestDrive:crypt/ippqhs6o8n8f9aihb4n2s696sijniukgi2cvh83jmt0ape415uj0/31u3jie661vd5p8j7rtc3hgbh0" 2025/03/07 11:23:23 DEBUG : one: Sizes differ (src 4 vs dst 3) 2025/03/07 11:23:24 INFO : one: Moved (server-side) to: one.bak 2025/03/07 11:23:25 DEBUG : one: md5 = 9b759608bc3ab325ec0d03c5be24d85a OK 2025/03/07 11:23:25 INFO : one: Copied (new) 2025/03/07 11:23:25 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/03/07 11:23:25 DEBUG : two: Unchanged skipping 2025/03/07 11:23:26 DEBUG : three.txt: Sizes differ (src 6 vs dst 5) 2025/03/07 11:23:26 INFO : three.txt: Moved (server-side) to: three.txt.bak 2025/03/07 11:23:28 DEBUG : three.txt: md5 = 999d86306af2e4d7a0a1a69cb9336e2c OK 2025/03/07 11:23:28 INFO : three.txt: Copied (new) 2025/03/07 11:23:29 DEBUG : one: Sizes differ (src 5 vs dst 4) 2025/03/07 11:23:30 INFO : one.bak: Deleted 2025/03/07 11:23:30 INFO : one: Moved (server-side) to: one.bak 2025/03/07 11:23:32 DEBUG : one: md5 = 120c52910179d3d747635c7aa4202fc6 OK 2025/03/07 11:23:32 INFO : one: Copied (new) 2025/03/07 11:23:32 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/03/07 11:23:32 DEBUG : two: Unchanged skipping 2025/03/07 11:23:32 DEBUG : three.txt: Sizes differ (src 19 vs dst 6) 2025/03/07 11:23:33 INFO : three.txt.bak: Deleted 2025/03/07 11:23:33 INFO : three.txt: Moved (server-side) to: three.txt.bak 2025/03/07 11:23:35 DEBUG : three.txt: md5 = 3b9f3afe0b2feba5955af78666fb6f18 OK 2025/03/07 11:23:35 INFO : three.txt: Copied (new) 2025/03/07 11:23:39 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" 2025/03/07 11:23:39 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "tr2hj63d80ftlmvm6a952snjcc" 2025/03/07 11:23:39 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "qltcak2uaegtmcoa8vijdppbp8" 2025/03/07 11:23:39 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "qltcak2uaegtmcoa8vijdppbp8" 2025/03/07 11:23:39 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "sk91qgsqfn0r271r2ehsaoc20c" 2025/03/07 11:23:39 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "sk91qgsqfn0r271r2ehsaoc20c" 2025/03/07 11:23:39 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k" --- PASS: TestSyncSuffix (23.15s) === RUN TestSyncSuffixKeepExtension run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-filesez1jaqi'", Local "Local file system at /tmp/rclone2831462366", Modify Window "1ms" 2025/03/07 11:23:42 DEBUG : dst/one: md5 = 064051b107c0446aca81e4cfc57957e3 OK 2025/03/07 11:23:43 DEBUG : dst/two: md5 = 57727d2c05c63c27e290583b1adfd871 OK 2025/03/07 11:23:45 DEBUG : dst/three.txt: md5 = c0b4ed6688429803955896c577ac0c98 OK 2025/03/07 11:23:45 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-filesez1jaqi/dst" 2025/03/07 11:23:45 DEBUG : Creating backend with remote "TestDrive:crypt/ippqhs6o8n8f9aihb4n2s696sijniukgi2cvh83jmt0ape415uj0/31u3jie661vd5p8j7rtc3hgbh0" 2025/03/07 11:23:46 DEBUG : one: Sizes differ (src 4 vs dst 3) 2025/03/07 11:23:47 INFO : one: Moved (server-side) to: one-2019-01-01 2025/03/07 11:23:49 DEBUG : one: md5 = 55ee53d77a5eca01478876a918d9ee79 OK 2025/03/07 11:23:49 INFO : one: Copied (new) 2025/03/07 11:23:49 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/03/07 11:23:49 DEBUG : two: Unchanged skipping 2025/03/07 11:23:49 DEBUG : three.txt: Sizes differ (src 6 vs dst 5) 2025/03/07 11:23:50 INFO : three.txt: Moved (server-side) to: three-2019-01-01.txt 2025/03/07 11:23:51 DEBUG : three.txt: md5 = cde5162813d5c8da39a2b79ed8d48163 OK 2025/03/07 11:23:51 INFO : three.txt: Copied (new) 2025/03/07 11:23:52 DEBUG : one: Sizes differ (src 5 vs dst 4) 2025/03/07 11:23:53 INFO : one-2019-01-01: Deleted 2025/03/07 11:23:54 INFO : one: Moved (server-side) to: one-2019-01-01 2025/03/07 11:23:55 DEBUG : one: md5 = 9b433af226d2e83d280e3da75caff603 OK 2025/03/07 11:23:55 INFO : one: Copied (new) 2025/03/07 11:23:55 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/03/07 11:23:55 DEBUG : two: Unchanged skipping 2025/03/07 11:23:56 DEBUG : three.txt: Sizes differ (src 19 vs dst 6) 2025/03/07 11:23:56 INFO : three-2019-01-01.txt: Deleted 2025/03/07 11:23:57 INFO : three.txt: Moved (server-side) to: three-2019-01-01.txt 2025/03/07 11:23:58 DEBUG : three.txt: md5 = 1c33d7c6be162f8ce2e1f8a98878c8c9 OK 2025/03/07 11:23:58 INFO : three.txt: Copied (new) 2025/03/07 11:24:02 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" 2025/03/07 11:24:02 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "tr2hj63d80ftlmvm6a952snjcc" 2025/03/07 11:24:02 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "jcjl1bv3ep0v8kt35lqql1co90" 2025/03/07 11:24:02 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k" 2025/03/07 11:24:02 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "qtq2f6qq4lgpsmj88vb7147qje3prudmtfdtr2342fth58vo9a50" 2025/03/07 11:24:02 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "qtq2f6qq4lgpsmj88vb7147qje3prudmtfdtr2342fth58vo9a50" 2025/03/07 11:24:02 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "jcjl1bv3ep0v8kt35lqql1co90" --- PASS: TestSyncSuffixKeepExtension (23.15s) === RUN TestSyncUTFNorm run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-filesez1jaqi'", Local "Local file system at /tmp/rclone2831462366", Modify Window "1ms" 2025/03/07 11:24:04 DEBUG : Testêé: md5 = b89aedfa01a460212a43e710cae49f1d OK 2025/03/07 11:24:05 DEBUG : Testêé: Sizes differ (src 14 vs dst 18) 2025/03/07 11:24:05 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-filesez1jaqi': Waiting for checks to finish 2025/03/07 11:24:05 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-filesez1jaqi': Waiting for transfers to finish 2025/03/07 11:24:06 DEBUG : Testêé: md5 = 55ebc15e74c8208b62e67cf13991ca94 OK 2025/03/07 11:24:06 INFO : Testêé: Copied (replaced existing) to: Testêé 2025/03/07 11:24:06 DEBUG : Waiting for deletions to finish --- PASS: TestSyncUTFNorm (4.35s) === RUN TestSyncImmutable run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-filesez1jaqi'", Local "Local file system at /tmp/rclone2831462366", Modify Window "1ms" 2025/03/07 11:24:07 DEBUG : existing: Need to transfer - File not found at Destination 2025/03/07 11:24:07 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-filesez1jaqi': Waiting for checks to finish 2025/03/07 11:24:07 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-filesez1jaqi': Waiting for transfers to finish 2025/03/07 11:24:09 DEBUG : existing: md5 = ce93de072645a463b75fa44adc40aee9 OK 2025/03/07 11:24:09 INFO : existing: Copied (new) 2025/03/07 11:24:09 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-filesez1jaqi'", Local "Local file system at /tmp/rclone2831462366", Modify Window "1ms" 2025/03/07 11:24:10 DEBUG : existing: Sizes differ (src 8 vs dst 6) 2025/03/07 11:24:10 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-filesez1jaqi': Waiting for checks to finish 2025/03/07 11:24:10 ERROR : existing: Source and destination exist but do not match: immutable file modified 2025/03/07 11:24:10 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-filesez1jaqi': Waiting for transfers to finish 2025/03/07 11:24:10 ERROR : Encrypted drive 'TestCryptDrive:rclone-test-filesez1jaqi': not deleting files as there were IO errors 2025/03/07 11:24:10 ERROR : Encrypted drive 'TestCryptDrive:rclone-test-filesez1jaqi': not deleting directories as there were IO errors run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-filesez1jaqi'", Local "Local file system at /tmp/rclone2831462366", Modify Window "1ms" --- PASS: TestSyncImmutable (4.67s) === RUN TestSyncIgnoreCase run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-filesez1jaqi'", Local "Local file system at /tmp/rclone2831462366", Modify Window "1ms" 2025/03/07 11:24:13 DEBUG : EXISTING: md5 = ea3091912125ba651af7da7bded0ef15 OK 2025/03/07 11:24:14 DEBUG : existing: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/03/07 11:24:14 DEBUG : existing: Unchanged skipping 2025/03/07 11:24:14 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-filesez1jaqi': Waiting for checks to finish 2025/03/07 11:24:14 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-filesez1jaqi': Waiting for transfers to finish 2025/03/07 11:24:14 DEBUG : Waiting for deletions to finish 2025/03/07 11:24:14 INFO : There was nothing to transfer --- PASS: TestSyncIgnoreCase (3.35s) === RUN TestFixCase run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-filesez1jaqi'", Local "Local file system at /tmp/rclone2831462366", Modify Window "1ms" sync_test.go:2635: Skipping test as local or remote are case-sensitive --- SKIP: TestFixCase (0.46s) === RUN TestMaxTransfer === RUN TestMaxTransfer/Hard run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-filesez1jaqi'", Local "Local file system at /tmp/rclone2831462366", 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-filesez1jaqi'", Local "Local file system at /tmp/rclone2831462366", 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-filesez1jaqi'", Local "Local file system at /tmp/rclone2831462366", Modify Window "1ms" sync_test.go:2674: This test only runs on local --- PASS: TestMaxTransfer (1.42s) --- SKIP: TestMaxTransfer/Hard (0.47s) --- SKIP: TestMaxTransfer/Soft (0.47s) --- SKIP: TestMaxTransfer/Cautious (0.48s) === RUN TestSyncConcurrentDelete run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-filesez1jaqi'", Local "Local file system at /tmp/rclone2831462366", Modify Window "1ms" 2025/03/07 11:24:18 DEBUG : both0: md5 = 0c54b0702af9db776f13ed1a2cf40c28 OK 2025/03/07 11:24:20 DEBUG : only0: md5 = 36e387d03c1a4331612a4b6f1a521c27 OK 2025/03/07 11:24:21 DEBUG : both1: md5 = 0a5b390999e6daf5c07e74997c27d5cd OK 2025/03/07 11:24:23 DEBUG : only1: md5 = b1b111f9fd049513d747c5b0f393f2bf OK 2025/03/07 11:24:24 DEBUG : both2: md5 = 9feb81bff546b3b9ec05359ef67d3e60 OK 2025/03/07 11:24:26 DEBUG : only2: md5 = ba05520a2687aebfe85fe75daddac2a3 OK 2025/03/07 11:24:27 DEBUG : both3: md5 = 40852cd39b25164515ae34f8cfb6deff OK 2025/03/07 11:24:28 DEBUG : only3: md5 = ee133883642534da557f484b36c5333d OK 2025/03/07 11:24:30 DEBUG : both4: md5 = 0e2a29840690ae7aa51b0d7d1302ba06 OK 2025/03/07 11:24:31 DEBUG : only4: md5 = 0f517553bb80f7ad6e784da9340f4b1d OK 2025/03/07 11:24:32 DEBUG : both5: md5 = 1124ce33bf73e17d20fe0a5b51b9d050 OK 2025/03/07 11:24:34 DEBUG : only5: md5 = d72312784c7d270933035b9c9febf3fa OK 2025/03/07 11:24:35 DEBUG : both6: md5 = 09a2fab6ffca289e41988faef9be20aa OK 2025/03/07 11:24:37 DEBUG : only6: md5 = 9d8ecca3991433d45efcedfa259a735b OK 2025/03/07 11:24:38 DEBUG : both7: md5 = d39015465108362e02ef7e95ddf1052c OK 2025/03/07 11:24:40 DEBUG : only7: md5 = aff5e6240a8fc85bcfd831f940ed92df OK 2025/03/07 11:24:41 DEBUG : both8: md5 = ba8747f484fe98753840dd25402f7ffd OK 2025/03/07 11:24:42 DEBUG : only8: md5 = 3ac245ae1ba239459718af9e17323b3c OK 2025/03/07 11:24:44 DEBUG : both9: md5 = f3591630d3b6850d34a801a24eb36eed OK 2025/03/07 11:24:45 DEBUG : only9: md5 = 9b71cb7f31a3cdcd1aed4915e6240f0d OK 2025/03/07 11:24:47 DEBUG : both10: md5 = 2c83d07f7a7decf7422295e0770be555 OK 2025/03/07 11:24:48 DEBUG : only10: md5 = 7cdded162ff821306516e7fcaa31be3f OK 2025/03/07 11:24:50 DEBUG : both11: md5 = 4af4341320c499ec0ad3949f36eedd65 OK 2025/03/07 11:24:51 DEBUG : only11: md5 = 517420793e6e62f9496dbd3329283a68 OK 2025/03/07 11:24:52 DEBUG : both12: md5 = d6448c11a302883d3ab19d4f09935799 OK 2025/03/07 11:24:54 DEBUG : only12: md5 = 0352e0683f392a3e70d8e76e15397193 OK 2025/03/07 11:24:55 DEBUG : both13: md5 = 0c955e077af522f8f1bb4cace2c30a6f OK 2025/03/07 11:24:57 DEBUG : only13: md5 = 4adec1fedaf954f434cfb94f1d7f16b9 OK 2025/03/07 11:24:58 DEBUG : both14: md5 = 6859dc096869d214202dd9f43dd31c6c OK 2025/03/07 11:24:59 DEBUG : only14: md5 = 3c1e9dd2b63baaddd489ec64ba80ac6a OK 2025/03/07 11:25:01 DEBUG : both15: md5 = 47496e308fd8523f94999f418967a59c OK 2025/03/07 11:25:02 DEBUG : only15: md5 = 3418edfaa4111e8bea756508ad388c82 OK 2025/03/07 11:25:03 DEBUG : both16: md5 = 4c0ba0fdeafc1af1ebf63fa04801da43 OK 2025/03/07 11:25:05 DEBUG : only16: md5 = 40308759ba6b1bc043e2440dde0caab6 OK 2025/03/07 11:25:06 DEBUG : both17: md5 = 19862afa85541ae1aa93a852e4790adf OK 2025/03/07 11:25:07 DEBUG : only17: md5 = b03fbef25c5ed30b2a74b16d44b5ce4b OK 2025/03/07 11:25:09 DEBUG : both18: md5 = f8438f24ab48d7962230bae0bcaa27ed OK 2025/03/07 11:25:10 DEBUG : only18: md5 = b70f2207aae9162355349f84c8399735 OK 2025/03/07 11:25:12 DEBUG : both19: md5 = 18b218fa1e50d54fd2feba1aa49e8122 OK 2025/03/07 11:25:13 DEBUG : only19: md5 = e675ad6ca334356281d760edacbd1216 OK 2025/03/07 11:25:14 DEBUG : both0: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/03/07 11:25:14 DEBUG : both1: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/03/07 11:25:14 DEBUG : both10: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/03/07 11:25:14 DEBUG : both11: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/03/07 11:25:14 DEBUG : both0: Unchanged skipping 2025/03/07 11:25:14 DEBUG : both12: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/03/07 11:25:14 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-filesez1jaqi': Waiting for checks to finish 2025/03/07 11:25:14 DEBUG : both11: Unchanged skipping 2025/03/07 11:25:14 DEBUG : both13: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/03/07 11:25:14 DEBUG : both13: Unchanged skipping 2025/03/07 11:25:14 DEBUG : both14: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/03/07 11:25:14 DEBUG : both14: Unchanged skipping 2025/03/07 11:25:14 DEBUG : both15: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/03/07 11:25:14 DEBUG : both15: Unchanged skipping 2025/03/07 11:25:14 DEBUG : both16: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/03/07 11:25:14 DEBUG : both12: Unchanged skipping 2025/03/07 11:25:14 DEBUG : both17: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/03/07 11:25:14 DEBUG : both10: Unchanged skipping 2025/03/07 11:25:14 DEBUG : both18: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/03/07 11:25:14 DEBUG : both1: Unchanged skipping 2025/03/07 11:25:14 DEBUG : both19: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/03/07 11:25:14 DEBUG : both19: Unchanged skipping 2025/03/07 11:25:14 DEBUG : both2: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/03/07 11:25:14 DEBUG : both16: Unchanged skipping 2025/03/07 11:25:14 DEBUG : both3: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/03/07 11:25:14 DEBUG : both3: Unchanged skipping 2025/03/07 11:25:14 DEBUG : both4: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/03/07 11:25:14 DEBUG : both4: Unchanged skipping 2025/03/07 11:25:14 DEBUG : both5: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/03/07 11:25:14 DEBUG : both5: Unchanged skipping 2025/03/07 11:25:14 DEBUG : both6: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/03/07 11:25:14 DEBUG : both6: Unchanged skipping 2025/03/07 11:25:14 DEBUG : both7: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/03/07 11:25:14 DEBUG : both17: Unchanged skipping 2025/03/07 11:25:14 DEBUG : both8: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/03/07 11:25:14 DEBUG : both18: Unchanged skipping 2025/03/07 11:25:14 DEBUG : both9: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/03/07 11:25:14 DEBUG : both2: Unchanged skipping 2025/03/07 11:25:14 DEBUG : both7: Unchanged skipping 2025/03/07 11:25:14 DEBUG : both8: Unchanged skipping 2025/03/07 11:25:14 DEBUG : both9: Unchanged skipping 2025/03/07 11:25:14 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-filesez1jaqi': Waiting for transfers to finish 2025/03/07 11:25:14 DEBUG : Waiting for deletions to finish 2025/03/07 11:25:14 INFO : only6: Deleted 2025/03/07 11:25:14 INFO : only18: Deleted 2025/03/07 11:25:14 INFO : only12: Deleted 2025/03/07 11:25:14 INFO : only3: Deleted 2025/03/07 11:25:15 INFO : only19: Deleted 2025/03/07 11:25:15 INFO : only17: Deleted 2025/03/07 11:25:15 INFO : only4: Deleted 2025/03/07 11:25:15 INFO : only5: Deleted 2025/03/07 11:25:15 INFO : only8: Deleted 2025/03/07 11:25:15 INFO : only0: Deleted 2025/03/07 11:25:15 INFO : only13: Deleted 2025/03/07 11:25:15 INFO : only11: Deleted 2025/03/07 11:25:16 INFO : only14: Deleted 2025/03/07 11:25:16 INFO : only15: Deleted 2025/03/07 11:25:16 INFO : only2: Deleted 2025/03/07 11:25:16 INFO : only16: Deleted 2025/03/07 11:25:16 INFO : only9: Deleted 2025/03/07 11:25:16 INFO : only10: Deleted 2025/03/07 11:25:16 INFO : only7: Deleted 2025/03/07 11:25:16 INFO : only1: Deleted 2025/03/07 11:25:16 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-filesez1jaqi'", Local "Local file system at /tmp/rclone2831462366", Modify Window "1ms" --- PASS: TestSyncConcurrentDelete (70.56s) === RUN TestSyncConcurrentTruncate run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-filesez1jaqi'", Local "Local file system at /tmp/rclone2831462366", Modify Window "1ms" 2025/03/07 11:25:29 DEBUG : both0: md5 = 69cf6b8225591dbacdca39204acb363c OK 2025/03/07 11:25:30 DEBUG : only0: md5 = 492c7b4692b5e6c1bc76496b7747164e OK 2025/03/07 11:25:32 DEBUG : both1: md5 = 309d124d05224fb3a8d8310c98395f96 OK 2025/03/07 11:25:33 DEBUG : only1: md5 = e42b760145507ca25a3b9f4edfeb33d1 OK 2025/03/07 11:25:35 DEBUG : both2: md5 = 1d1e60b75ee330eb980eea605792f683 OK 2025/03/07 11:25:36 DEBUG : only2: md5 = c5f9ab3dcffd74e719dfd9ca31af5be9 OK 2025/03/07 11:25:38 DEBUG : both3: md5 = 45d52a02a3418121d010b5ff4bab6469 OK 2025/03/07 11:25:39 DEBUG : only3: md5 = 3a2891259d09b0777240b85df2bb4b8f OK 2025/03/07 11:25:40 DEBUG : both4: md5 = 635fc72c93ea5fa54da05b2f2d600109 OK 2025/03/07 11:25:42 DEBUG : only4: md5 = ea6b622f994fc0cf6277925592544652 OK 2025/03/07 11:25:43 DEBUG : both5: md5 = 14807765fdbd990b66f9b333272a27a8 OK 2025/03/07 11:25:45 DEBUG : only5: md5 = 08481178793e2c4cce8ba54884bb1f59 OK 2025/03/07 11:25:46 DEBUG : both6: md5 = c3693bf0ddd28f50006e7878f5ff6d84 OK 2025/03/07 11:25:47 DEBUG : only6: md5 = 4f6047ea46714cdea180c0528bd1ea19 OK 2025/03/07 11:25:49 DEBUG : both7: md5 = 62cf363c34845c4de3b3ec640f460111 OK 2025/03/07 11:25:50 DEBUG : only7: md5 = 2961076903954dec6b1b0bcd3fd65b6d OK 2025/03/07 11:25:52 DEBUG : both8: md5 = 3c8a7ae374e4f86f9619cc4c04c1d180 OK 2025/03/07 11:25:53 DEBUG : only8: md5 = 5958397ef3703a42bc64dbcfa8c6b0fc OK 2025/03/07 11:25:55 DEBUG : both9: md5 = 23945de07fe8553d5351d939f95717fb OK 2025/03/07 11:25:56 DEBUG : only9: md5 = 552e8c96efe788f4a37b2366df04ba89 OK 2025/03/07 11:25:58 DEBUG : both10: md5 = 3b718967174d8f4d302a73cfd28d91c6 OK 2025/03/07 11:25:59 DEBUG : only10: md5 = a04f07cce2ffb1216070bd90bbd94f5e OK 2025/03/07 11:26:01 DEBUG : both11: md5 = 14280b553f4bab90fa9e506acbb2a8c7 OK 2025/03/07 11:26:02 DEBUG : only11: md5 = 9c996a9bea850888ec706a5b29aeb02d OK 2025/03/07 11:26:04 DEBUG : both12: md5 = a297b02212f08c3414cba46fb6a39241 OK 2025/03/07 11:26:05 DEBUG : only12: md5 = c1f8b42377a4c3844297c9d9b31990ed OK 2025/03/07 11:26:06 DEBUG : both13: md5 = da095b610c1660f97d08d4b9eb48a69c OK 2025/03/07 11:26:08 DEBUG : only13: md5 = 5b04c478d491d0ed346afcb60368c776 OK 2025/03/07 11:26:09 DEBUG : both14: md5 = f4ac8c48ab39eb1ccfb71702e3d4b84b OK 2025/03/07 11:26:11 DEBUG : only14: md5 = 8d4a62c70285d3b63acfac7884cf9cdc OK 2025/03/07 11:26:12 DEBUG : both15: md5 = 97cdd5bdffd149c31b14b8dc1c4931ff OK 2025/03/07 11:26:14 DEBUG : only15: md5 = 68031fabb9f4bacef10ba74e0c8a8866 OK 2025/03/07 11:26:15 DEBUG : both16: md5 = bb40e9acd0d8ab1a5aee0f1a5e4f4963 OK 2025/03/07 11:26:17 DEBUG : only16: md5 = b4627b08a91ad3cd3f0185df71812c76 OK 2025/03/07 11:26:18 DEBUG : both17: md5 = 6410d8270c85f04ae089d1d4266d1db0 OK 2025/03/07 11:26:19 DEBUG : only17: md5 = 444c721ee0f1c841bc7d07cddd46e103 OK 2025/03/07 11:26:20 DEBUG : both18: md5 = 364c7228c9b8295ebfbe1417ed6db077 OK 2025/03/07 11:26:22 DEBUG : only18: md5 = a6092fafb850f038a1969eccddf6646f OK 2025/03/07 11:26:23 DEBUG : both19: md5 = 270ba245ceb5ab044b3b62be854538a6 OK 2025/03/07 11:26:25 DEBUG : only19: md5 = 7d73ff57dbd5a05ca0d8df7432ce6fd7 OK 2025/03/07 11:26:25 DEBUG : both1: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/03/07 11:26:25 DEBUG : both0: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/03/07 11:26:25 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-filesez1jaqi': Waiting for checks to finish 2025/03/07 11:26:25 DEBUG : both10: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/03/07 11:26:25 DEBUG : both11: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/03/07 11:26:25 DEBUG : both1: Unchanged skipping 2025/03/07 11:26:25 DEBUG : both12: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/03/07 11:26:25 DEBUG : both11: Unchanged skipping 2025/03/07 11:26:25 DEBUG : both13: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/03/07 11:26:25 DEBUG : both12: Unchanged skipping 2025/03/07 11:26:25 DEBUG : both14: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/03/07 11:26:25 DEBUG : both14: Unchanged skipping 2025/03/07 11:26:25 DEBUG : both15: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/03/07 11:26:25 DEBUG : both10: Unchanged skipping 2025/03/07 11:26:25 DEBUG : both16: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/03/07 11:26:25 DEBUG : both16: Unchanged skipping 2025/03/07 11:26:25 DEBUG : both17: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/03/07 11:26:25 DEBUG : both17: Unchanged skipping 2025/03/07 11:26:25 DEBUG : both18: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/03/07 11:26:25 DEBUG : both18: Unchanged skipping 2025/03/07 11:26:25 DEBUG : both19: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/03/07 11:26:25 DEBUG : both19: Unchanged skipping 2025/03/07 11:26:25 DEBUG : both2: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/03/07 11:26:25 DEBUG : both2: Unchanged skipping 2025/03/07 11:26:25 DEBUG : both3: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/03/07 11:26:25 DEBUG : both3: Unchanged skipping 2025/03/07 11:26:25 DEBUG : both4: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/03/07 11:26:25 DEBUG : both4: Unchanged skipping 2025/03/07 11:26:25 DEBUG : both5: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/03/07 11:26:25 DEBUG : both5: Unchanged skipping 2025/03/07 11:26:25 DEBUG : both6: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/03/07 11:26:25 DEBUG : both6: Unchanged skipping 2025/03/07 11:26:25 DEBUG : both7: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/03/07 11:26:25 DEBUG : both7: Unchanged skipping 2025/03/07 11:26:25 DEBUG : both8: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/03/07 11:26:25 DEBUG : both8: Unchanged skipping 2025/03/07 11:26:25 DEBUG : both9: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/03/07 11:26:25 DEBUG : both9: Unchanged skipping 2025/03/07 11:26:25 DEBUG : only0: Sizes differ (src 0 vs dst 6) 2025/03/07 11:26:25 DEBUG : only1: Sizes differ (src 0 vs dst 6) 2025/03/07 11:26:25 DEBUG : both15: Unchanged skipping 2025/03/07 11:26:25 DEBUG : only10: Sizes differ (src 0 vs dst 6) 2025/03/07 11:26:25 DEBUG : only11: Sizes differ (src 0 vs dst 6) 2025/03/07 11:26:25 DEBUG : only12: Sizes differ (src 0 vs dst 6) 2025/03/07 11:26:25 DEBUG : only13: Sizes differ (src 0 vs dst 6) 2025/03/07 11:26:25 DEBUG : only14: Sizes differ (src 0 vs dst 6) 2025/03/07 11:26:25 DEBUG : only16: Sizes differ (src 0 vs dst 6) 2025/03/07 11:26:25 DEBUG : only17: Sizes differ (src 0 vs dst 6) 2025/03/07 11:26:25 DEBUG : only18: Sizes differ (src 0 vs dst 6) 2025/03/07 11:26:25 DEBUG : only15: Sizes differ (src 0 vs dst 6) 2025/03/07 11:26:25 DEBUG : only19: Sizes differ (src 0 vs dst 6) 2025/03/07 11:26:25 DEBUG : only2: Sizes differ (src 0 vs dst 6) 2025/03/07 11:26:25 DEBUG : only3: Sizes differ (src 0 vs dst 6) 2025/03/07 11:26:25 DEBUG : both0: Unchanged skipping 2025/03/07 11:26:25 DEBUG : only4: Sizes differ (src 0 vs dst 6) 2025/03/07 11:26:25 DEBUG : both13: Unchanged skipping 2025/03/07 11:26:25 DEBUG : only5: Sizes differ (src 0 vs dst 6) 2025/03/07 11:26:25 DEBUG : only6: Sizes differ (src 0 vs dst 6) 2025/03/07 11:26:25 DEBUG : only7: Sizes differ (src 0 vs dst 6) 2025/03/07 11:26:25 DEBUG : only8: Sizes differ (src 0 vs dst 6) 2025/03/07 11:26:25 DEBUG : only9: Sizes differ (src 0 vs dst 6) 2025/03/07 11:26:25 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-filesez1jaqi': Waiting for transfers to finish 2025/03/07 11:26:26 DEBUG : only11: md5 = 1cfe4c4a6012b7f9e4c54e7aecfba99a OK 2025/03/07 11:26:26 INFO : only11: Copied (replaced existing) 2025/03/07 11:26:27 DEBUG : only10: md5 = 08529b05c2b25e3e673887ccbbb8eee1 OK 2025/03/07 11:26:27 INFO : only10: Copied (replaced existing) 2025/03/07 11:26:27 DEBUG : only12: md5 = e62522b2263cd6e6fcbe4afb60cd737f OK 2025/03/07 11:26:27 INFO : only12: Copied (replaced existing) 2025/03/07 11:26:27 DEBUG : only0: md5 = fef6fe9aaec593b8d35344b5a38a7aec OK 2025/03/07 11:26:27 INFO : only0: Copied (replaced existing) 2025/03/07 11:26:28 DEBUG : only1: md5 = 4d9a74fabfe6bfe1369257095f3bbfbb OK 2025/03/07 11:26:28 INFO : only1: Copied (replaced existing) 2025/03/07 11:26:28 DEBUG : only14: md5 = 6941d6f617a98c431185fedb0b515e50 OK 2025/03/07 11:26:28 INFO : only14: Copied (replaced existing) 2025/03/07 11:26:28 DEBUG : only16: md5 = 3a7ca2d665d114b0f02c717fe004f2d0 OK 2025/03/07 11:26:28 INFO : only16: Copied (replaced existing) 2025/03/07 11:26:28 DEBUG : only13: md5 = ae1b2214605c249058209cd090b4c73c OK 2025/03/07 11:26:28 INFO : only13: Copied (replaced existing) 2025/03/07 11:26:29 DEBUG : only17: md5 = 48363fd1acef5137de01b06b8029b0c0 OK 2025/03/07 11:26:29 INFO : only17: Copied (replaced existing) 2025/03/07 11:26:29 DEBUG : only15: md5 = 482483a88c2de1a8e193e2567ef694e7 OK 2025/03/07 11:26:29 INFO : only15: Copied (replaced existing) 2025/03/07 11:26:29 DEBUG : only19: md5 = 5d443e868c9dbe5a86210778e9f5b580 OK 2025/03/07 11:26:29 INFO : only19: Copied (replaced existing) 2025/03/07 11:26:29 DEBUG : only18: md5 = 482b3eb9ab69738aeefded790dbb96ec OK 2025/03/07 11:26:29 INFO : only18: Copied (replaced existing) 2025/03/07 11:26:30 DEBUG : only6: md5 = c81d86bfbdb8e13c0575fef996ad26fb OK 2025/03/07 11:26:30 INFO : only6: Copied (replaced existing) 2025/03/07 11:26:30 DEBUG : only7: md5 = 21960549e0a0645428f278d2f5ba529b OK 2025/03/07 11:26:30 INFO : only7: Copied (replaced existing) 2025/03/07 11:26:30 DEBUG : only2: md5 = 8b5c3c8691301fb81f9e096969d581db OK 2025/03/07 11:26:30 INFO : only2: Copied (replaced existing) 2025/03/07 11:26:31 DEBUG : only8: md5 = 237638a4230e7e7359b0614a07947abf OK 2025/03/07 11:26:31 INFO : only8: Copied (replaced existing) 2025/03/07 11:26:31 DEBUG : only3: md5 = 043be957844ce265c2ef2c2309d0c77d OK 2025/03/07 11:26:31 INFO : only3: Copied (replaced existing) 2025/03/07 11:26:31 DEBUG : only9: md5 = d1781c737c0fa7e0ca61cc303dc0dfb0 OK 2025/03/07 11:26:31 INFO : only9: Copied (replaced existing) 2025/03/07 11:26:31 DEBUG : only4: md5 = 024d22e52408780c469e31d9a010e871 OK 2025/03/07 11:26:31 INFO : only4: Copied (replaced existing) 2025/03/07 11:26:32 DEBUG : only5: md5 = e64c9af3b7df49b09d14eabcf7a4aa18 OK 2025/03/07 11:26:32 INFO : only5: Copied (replaced existing) 2025/03/07 11:26:32 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-filesez1jaqi'", Local "Local file system at /tmp/rclone2831462366", Modify Window "1ms" --- PASS: TestSyncConcurrentTruncate (84.19s) === RUN TestSyncReplaceDirModTime run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-filesez1jaqi'", Local "Local file system at /tmp/rclone2831462366", Modify Window "1ms" 2025/03/07 11:26:52 DEBUG : empty_dir: Making directory with metadata 2025/03/07 11:26:52 INFO : empty_dir: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2025/03/07 11:26:52 DEBUG : empty_on_remote: Making directory with metadata 2025/03/07 11:26:52 INFO : empty_on_remote: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2025/03/07 11:26:52 DEBUG : empty_on_remote: Making directory with metadata 2025/03/07 11:26:52 INFO : empty_on_remote: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-filesez1jaqi'", Local "Local file system at /tmp/rclone2831462366", Modify Window "1ms" 2025/03/07 11:26:58 INFO : test_dir1: Set directory modification time (using DirSetModTime) 2025/03/07 11:26:58 INFO : test_dir2: Set directory modification time (using DirSetModTime) 2025/03/07 11:26:58 INFO : test_dir2/sub_dir: Set directory modification time (using DirSetModTime) 2025/03/07 11:26:58 INFO : empty_on_remote: Set directory modification time (using DirSetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-filesez1jaqi'", Local "Local file system at /tmp/rclone2831462366", Modify Window "1ms" 2025/03/07 11:27:05 DEBUG : heqj02jg0dcqlem7gl0500bvp0/24g2k8bseitblkmqnie1ibl2s8: Rmdir: contains trashed file: "633fmaa0qic3kv3cladnu11pto" 2025/03/07 11:27:05 DEBUG : heqj02jg0dcqlem7gl0500bvp0: Rmdir: contains trashed file: "24g2k8bseitblkmqnie1ibl2s8" 2025/03/07 11:27:06 DEBUG : gq68srrpl0nnf394bgf7dbu9kc: Rmdir: contains trashed file: "d26uovf0miqhd1mu3c9jbseq00" --- PASS: TestSyncReplaceDirModTime (17.28s) === RUN TestSyncReplaceDirModTimeWithEmptyDirs run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-filesez1jaqi'", Local "Local file system at /tmp/rclone2831462366", Modify Window "1ms" 2025/03/07 11:27:09 DEBUG : empty_dir: Making directory with metadata 2025/03/07 11:27:09 INFO : empty_dir: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2025/03/07 11:27:09 DEBUG : empty_on_remote: Making directory with metadata 2025/03/07 11:27:09 INFO : empty_on_remote: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2025/03/07 11:27:09 DEBUG : empty_on_remote: Making directory with metadata 2025/03/07 11:27:10 INFO : empty_on_remote: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-filesez1jaqi'", Local "Local file system at /tmp/rclone2831462366", Modify Window "1ms" 2025/03/07 11:27:15 INFO : test_dir1: Set directory modification time (using DirSetModTime) 2025/03/07 11:27:15 INFO : test_dir2: Set directory modification time (using DirSetModTime) 2025/03/07 11:27:15 INFO : test_dir2/sub_dir: Set directory modification time (using DirSetModTime) 2025/03/07 11:27:15 INFO : empty_on_remote: Set directory modification time (using DirSetModTime) 2025/03/07 11:27:15 INFO : empty_dir: Set directory modification time (using DirSetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-filesez1jaqi'", Local "Local file system at /tmp/rclone2831462366", Modify Window "1ms" 2025/03/07 11:27:22 DEBUG : heqj02jg0dcqlem7gl0500bvp0/24g2k8bseitblkmqnie1ibl2s8: Rmdir: contains trashed file: "633fmaa0qic3kv3cladnu11pto" 2025/03/07 11:27:23 DEBUG : heqj02jg0dcqlem7gl0500bvp0: Rmdir: contains trashed file: "24g2k8bseitblkmqnie1ibl2s8" 2025/03/07 11:27:24 DEBUG : gq68srrpl0nnf394bgf7dbu9kc: Rmdir: contains trashed file: "d26uovf0miqhd1mu3c9jbseq00" --- PASS: TestSyncReplaceDirModTimeWithEmptyDirs (17.75s) === RUN TestNothingToTransferWithEmptyDirs run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-filesez1jaqi'", Local "Local file system at /tmp/rclone2831462366", Modify Window "1ms" 2025/03/07 11:27:27 INFO : sub dir: Set directory modification time (using DirSetModTime) 2025/03/07 11:27:27 DEBUG : sub dir: Making directory with metadata 2025/03/07 11:27:27 INFO : sub dir: Made directory with metadata (mtime=2011-12-30T12:59:59Z) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-filesez1jaqi'", Local "Local file system at /tmp/rclone2831462366", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-filesez1jaqi'", Local "Local file system at /tmp/rclone2831462366", Modify Window "1ms" 2025/03/07 11:27:45 INFO : sub dir2: Set directory modification time (using DirSetModTime) 2025/03/07 11:27:46 INFO : sub dir2: Set directory modification time (using DirSetModTime) 2025/03/07 11:27:46 INFO : sub dirEmpty/sub dirEmpty2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2025/03/07 11:27:46 INFO : sub dirEmpty: Set directory modification time (using DirSetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-filesez1jaqi'", Local "Local file system at /tmp/rclone2831462366", Modify Window "1ms" 2025/03/07 11:27:59 DEBUG : gcsdkq814sbtppue42dpsbg8ug: Rmdir: contains trashed file: "sjuo65gk5q3r1199jselk9k9o0" 2025/03/07 11:27:59 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/37qp6d1gohacv723ij3brofbu8/i24n0ln37pa2hv8pctddeuh73o: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" 2025/03/07 11:28:01 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/37qp6d1gohacv723ij3brofbu8: Rmdir: contains trashed file: "i24n0ln37pa2hv8pctddeuh73o" 2025/03/07 11:28:02 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "37qp6d1gohacv723ij3brofbu8" 2025/03/07 11:28:02 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak" 2025/03/07 11:28:03 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak" 2025/03/07 11:28:04 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak" 2025/03/07 11:28:04 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak" 2025/03/07 11:28:05 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/4r13oncfa2rsrr82oqhsqv24ns: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" 2025/03/07 11:28:06 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc: Rmdir: contains trashed file: "4r13oncfa2rsrr82oqhsqv24ns" 2025/03/07 11:28:06 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak" 2025/03/07 11:28:06 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestNothingToTransferWithEmptyDirs (41.83s) === RUN TestNothingToTransferWithoutEmptyDirs run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-filesez1jaqi'", Local "Local file system at /tmp/rclone2831462366", Modify Window "1ms" 2025/03/07 11:28:09 INFO : sub dir: Set directory modification time (using DirSetModTime) 2025/03/07 11:28:09 DEBUG : sub dir: Making directory with metadata 2025/03/07 11:28:09 INFO : sub dir: Made directory with metadata (mtime=2011-12-30T12:59:59Z) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-filesez1jaqi'", Local "Local file system at /tmp/rclone2831462366", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-filesez1jaqi'", Local "Local file system at /tmp/rclone2831462366", Modify Window "1ms" 2025/03/07 11:28:32 INFO : sub dir2: Set directory modification time (using DirSetModTime) 2025/03/07 11:28:32 INFO : sub dir2: Set directory modification time (using DirSetModTime) 2025/03/07 11:28:32 INFO : sub dirEmpty/sub dirEmpty2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2025/03/07 11:28:32 INFO : sub dirEmpty: Set directory modification time (using DirSetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-filesez1jaqi'", Local "Local file system at /tmp/rclone2831462366", Modify Window "1ms" 2025/03/07 11:28:44 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/37qp6d1gohacv723ij3brofbu8/i24n0ln37pa2hv8pctddeuh73o: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" 2025/03/07 11:28:44 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/37qp6d1gohacv723ij3brofbu8: Rmdir: contains trashed file: "i24n0ln37pa2hv8pctddeuh73o" 2025/03/07 11:28:45 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "37qp6d1gohacv723ij3brofbu8" 2025/03/07 11:28:46 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak" 2025/03/07 11:28:47 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak" 2025/03/07 11:28:47 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak" 2025/03/07 11:28:48 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak" 2025/03/07 11:28:49 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/4r13oncfa2rsrr82oqhsqv24ns: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" 2025/03/07 11:28:50 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc: Rmdir: contains trashed file: "4r13oncfa2rsrr82oqhsqv24ns" 2025/03/07 11:28:50 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak" 2025/03/07 11:28:50 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestNothingToTransferWithoutEmptyDirs (43.92s) PASS 2025/03/07 11:28:52 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-filesez1jaqi': Purge remote "./sync.test -test.v -test.timeout 1h0m0s -remote TestCryptDrive: -verbose" - Finished OK in 16m18.038054703s (try 1/5)