"./sync.test -test.v -test.timeout 1h0m0s -remote TestCryptDrive: -verbose" - Starting (try 1/5) 2024/12/19 01:55:45 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-hixiwuz4newu" 2024/12/19 01:55:45 DEBUG : Using config file from "/home/rclone/.rclone.conf" 2024/12/19 01:55:45 DEBUG : Creating backend with remote "TestDrive:crypt/migt86lmhkdmp5mgvq09tvu1uvaavurlpu91lhqg4rsp22d6epjg" 2024/12/19 01:55:46 DEBUG : Creating backend with remote "/tmp/rclone3755433712" === RUN TestPipe --- PASS: TestPipe (0.00s) === RUN TestPipeConcurrent --- PASS: TestPipeConcurrent (0.01s) === 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-hixiwuz4newu'", Local "Local file system at /tmp/rclone3755433712", Modify Window "1ms" 2024/12/19 01:55:47 DEBUG : Added delayed dir = "sub dir", newDst= 2024/12/19 01:55:47 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2024/12/19 01:55:47 NOTICE: sub dir/hello world: Skipped copy as --dry-run is set (size 11) 2024/12/19 01:55:47 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hixiwuz4newu': Waiting for checks to finish 2024/12/19 01:55:47 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hixiwuz4newu': Waiting for transfers to finish 2024/12/19 01:55:47 NOTICE: sub dir: Skipped set directory modification time as --dry-run is set run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-hixiwuz4newu'", Local "Local file system at /tmp/rclone3755433712", Modify Window "1ms" --- PASS: TestCopyWithDryRun (2.35s) === RUN TestCopy run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-hixiwuz4newu'", Local "Local file system at /tmp/rclone3755433712", Modify Window "1ms" 2024/12/19 01:55:48 INFO : sub dir: Set directory modification time (using DirSetModTime) 2024/12/19 01:55:48 DEBUG : Added delayed dir = "sub dir", newDst= 2024/12/19 01:55:48 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2024/12/19 01:55:48 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hixiwuz4newu': Waiting for checks to finish 2024/12/19 01:55:48 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hixiwuz4newu': Waiting for transfers to finish 2024/12/19 01:55:51 DEBUG : sub dir/hello world: md5 = 93721ce6d19178c5e045282b617862a3 OK 2024/12/19 01:55:51 INFO : sub dir/hello world: Copied (new) 2024/12/19 01:55:52 INFO : sub dir: Set directory modification time (using DirSetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-hixiwuz4newu'", Local "Local file system at /tmp/rclone3755433712", Modify Window "1ms" 2024/12/19 01:55:54 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestCopy (6.91s) === RUN TestCopyMetadata run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-hixiwuz4newu'", Local "Local file system at /tmp/rclone3755433712", Modify Window "1ms" 2024/12/19 01:55:55 DEBUG : metadata sub dir: Making directory with metadata 2024/12/19 01:55:55 INFO : metadata sub dir: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2024/12/19 01:55:55 DEBUG : empty metadata sub dir: Making directory with metadata 2024/12/19 01:55:55 INFO : empty metadata sub dir: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2024/12/19 01:55:55 DEBUG : Local file system at /tmp/rclone3755433712: File to upload is small (21 bytes), uploading instead of streaming 2024/12/19 01:55:55 DEBUG : metadata sub dir/hello metadata world: md5 = baa7a013449dbba2b1ed02b5cfb4e1a2 OK 2024/12/19 01:55:55 DEBUG : metadata sub dir/hello metadata world: Size and md5 of src and dst objects identical 2024/12/19 01:55:55 INFO : metadata sub dir: Set directory modification time (using DirSetModTime) 2024/12/19 01:55:56 DEBUG : Google drive root 'crypt/migt86lmhkdmp5mgvq09tvu1uvaavurlpu91lhqg4rsp22d6epjg': Skipping btime metadata as can't update it on an existing file: 2024-12-19T01:55:55.541732903Z 2024/12/19 01:55:56 INFO : empty metadata sub dir: Updated directory metadata 2024/12/19 01:55:56 DEBUG : Google drive root 'crypt/migt86lmhkdmp5mgvq09tvu1uvaavurlpu91lhqg4rsp22d6epjg': Skipping btime metadata as can't update it on an existing file: 2024-12-19T01:55:55.541732903Z 2024/12/19 01:55:57 INFO : metadata sub dir: Updated directory metadata 2024/12/19 01:55:57 DEBUG : metadata sub dir/hello metadata world: Need to transfer - File not found at Destination 2024/12/19 01:55:57 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hixiwuz4newu': Waiting for checks to finish 2024/12/19 01:55:57 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hixiwuz4newu': Waiting for transfers to finish 2024/12/19 01:55:59 DEBUG : metadata sub dir/hello metadata world: md5 = 5b1f8322a31cfa7ac0a6be06d17a0529 OK 2024/12/19 01:55:59 INFO : metadata sub dir/hello metadata world: Copied (new) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-hixiwuz4newu'", Local "Local file system at /tmp/rclone3755433712", Modify Window "1ms" 2024/12/19 01:56:02 DEBUG : fg45q1rm3kh00nmmkk4m6ihmrcnel1p7551kqhjr9bk2gtd2gbf0: Rmdir: contains trashed file: "dmuvulfij81f693ur0f1vvbvq9v6iscp56daas3m51n9li5e3470" --- PASS: TestCopyMetadata (8.83s) === RUN TestCopyMetadataNoEmptyDirs run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-hixiwuz4newu'", Local "Local file system at /tmp/rclone3755433712", Modify Window "1ms" 2024/12/19 01:56:04 DEBUG : metadata sub dir: Making directory with metadata 2024/12/19 01:56:04 INFO : metadata sub dir: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2024/12/19 01:56:04 DEBUG : empty metadata sub dir: Making directory with metadata 2024/12/19 01:56:04 INFO : empty metadata sub dir: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2024/12/19 01:56:04 DEBUG : Local file system at /tmp/rclone3755433712: File to upload is small (21 bytes), uploading instead of streaming 2024/12/19 01:56:04 DEBUG : metadata sub dir/hello metadata world: md5 = baa7a013449dbba2b1ed02b5cfb4e1a2 OK 2024/12/19 01:56:04 DEBUG : metadata sub dir/hello metadata world: Size and md5 of src and dst objects identical 2024/12/19 01:56:04 INFO : metadata sub dir: Set directory modification time (using DirSetModTime) 2024/12/19 01:56:04 DEBUG : Added delayed dir = "empty metadata sub dir", newDst= 2024/12/19 01:56:04 DEBUG : Added delayed dir = "metadata sub dir", newDst= 2024/12/19 01:56:04 DEBUG : metadata sub dir/hello metadata world: Need to transfer - File not found at Destination 2024/12/19 01:56:04 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hixiwuz4newu': Waiting for checks to finish 2024/12/19 01:56:04 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hixiwuz4newu': Waiting for transfers to finish 2024/12/19 01:56:07 DEBUG : metadata sub dir/hello metadata world: md5 = c372872ff132d3898c3430226a491b12 OK 2024/12/19 01:56:07 INFO : metadata sub dir/hello metadata world: Copied (new) 2024/12/19 01:56:07 DEBUG : Google drive root 'crypt/migt86lmhkdmp5mgvq09tvu1uvaavurlpu91lhqg4rsp22d6epjg': Skipping btime metadata as can't update it on an existing file: 2024-12-19T01:56:04.377604317Z 2024/12/19 01:56:07 INFO : metadata sub dir: Updated directory metadata run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-hixiwuz4newu'", Local "Local file system at /tmp/rclone3755433712", Modify Window "1ms" 2024/12/19 01:56:11 DEBUG : fg45q1rm3kh00nmmkk4m6ihmrcnel1p7551kqhjr9bk2gtd2gbf0: Rmdir: contains trashed file: "dmuvulfij81f693ur0f1vvbvq9v6iscp56daas3m51n9li5e3470" --- PASS: TestCopyMetadataNoEmptyDirs (8.30s) === RUN TestCopyMissingDirectory run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-hixiwuz4newu'", Local "Local file system at /tmp/rclone3755433712", Modify Window "1ms" 2024/12/19 01:56:12 DEBUG : Creating backend with remote "/non-existing" 2024/12/19 01:56:12 ERROR : Local file system at /non-existing: error reading source root directory: directory not found 2024/12/19 01:56:12 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hixiwuz4newu': Waiting for checks to finish 2024/12/19 01:56:12 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hixiwuz4newu': Waiting for transfers to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-hixiwuz4newu'", Local "Local file system at /tmp/rclone3755433712", Modify Window "1ms" --- PASS: TestCopyMissingDirectory (1.15s) === RUN TestCopyNoTraverse run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-hixiwuz4newu'", Local "Local file system at /tmp/rclone3755433712", Modify Window "1ms" 2024/12/19 01:56:13 DEBUG : Added delayed dir = "sub dir", newDst= 2024/12/19 01:56:14 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2024/12/19 01:56:14 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hixiwuz4newu': Waiting for checks to finish 2024/12/19 01:56:14 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hixiwuz4newu': Waiting for transfers to finish 2024/12/19 01:56:16 DEBUG : sub dir/hello world: md5 = 29020dad4c970ca14ba5d466e6a61b3a OK 2024/12/19 01:56:16 INFO : sub dir/hello world: Copied (new) 2024/12/19 01:56:17 INFO : sub dir: Set directory modification time (using DirSetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-hixiwuz4newu'", Local "Local file system at /tmp/rclone3755433712", Modify Window "1ms" 2024/12/19 01:56:19 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestCopyNoTraverse (6.70s) === RUN TestCopyCheckFirst run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-hixiwuz4newu'", Local "Local file system at /tmp/rclone3755433712", Modify Window "1ms" 2024/12/19 01:56:20 INFO : Encrypted drive 'TestCryptDrive:rclone-test-hixiwuz4newu': Running all checks before starting transfers 2024/12/19 01:56:20 DEBUG : Added delayed dir = "sub dir", newDst= 2024/12/19 01:56:20 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2024/12/19 01:56:20 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hixiwuz4newu': Waiting for checks to finish 2024/12/19 01:56:20 INFO : Encrypted drive 'TestCryptDrive:rclone-test-hixiwuz4newu': Checks finished, now starting transfers 2024/12/19 01:56:20 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hixiwuz4newu': Waiting for transfers to finish 2024/12/19 01:56:23 DEBUG : sub dir/hello world: md5 = 6e75e2bd978fc29c79d78238eb395f91 OK 2024/12/19 01:56:23 INFO : sub dir/hello world: Copied (new) 2024/12/19 01:56:23 INFO : sub dir: Set directory modification time (using DirSetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-hixiwuz4newu'", Local "Local file system at /tmp/rclone3755433712", Modify Window "1ms" 2024/12/19 01:56:25 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestCopyCheckFirst (6.67s) === RUN TestSyncNoTraverse run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-hixiwuz4newu'", Local "Local file system at /tmp/rclone3755433712", Modify Window "1ms" 2024/12/19 01:56:27 ERROR : Ignoring --no-traverse with sync 2024/12/19 01:56:27 DEBUG : Added delayed dir = "sub dir", newDst= 2024/12/19 01:56:27 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2024/12/19 01:56:27 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hixiwuz4newu': Waiting for checks to finish 2024/12/19 01:56:27 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hixiwuz4newu': Waiting for transfers to finish 2024/12/19 01:56:30 DEBUG : sub dir/hello world: md5 = a0e561956ae249a33360380c96f6a3f5 OK 2024/12/19 01:56:30 INFO : sub dir/hello world: Copied (new) 2024/12/19 01:56:30 DEBUG : Waiting for deletions to finish 2024/12/19 01:56:31 INFO : sub dir: Set directory modification time (using DirSetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-hixiwuz4newu'", Local "Local file system at /tmp/rclone3755433712", Modify Window "1ms" 2024/12/19 01:56:32 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestSyncNoTraverse (7.02s) === RUN TestCopyWithDepth run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-hixiwuz4newu'", Local "Local file system at /tmp/rclone3755433712", Modify Window "1ms" 2024/12/19 01:56:34 DEBUG : hello world2: Need to transfer - File not found at Destination 2024/12/19 01:56:34 DEBUG : Added delayed dir = "sub dir", newDst= 2024/12/19 01:56:34 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hixiwuz4newu': Waiting for checks to finish 2024/12/19 01:56:34 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hixiwuz4newu': Waiting for transfers to finish 2024/12/19 01:56:36 DEBUG : hello world2: md5 = 0730f36604fb27ae7d96480c835f4912 OK 2024/12/19 01:56:36 INFO : hello world2: Copied (new) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-hixiwuz4newu'", Local "Local file system at /tmp/rclone3755433712", Modify Window "1ms" --- PASS: TestCopyWithDepth (3.46s) === RUN TestCopyWithFilesFrom run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-hixiwuz4newu'", Local "Local file system at /tmp/rclone3755433712", Modify Window "1ms" 2024/12/19 01:56:37 DEBUG : potato2: Need to transfer - File not found at Destination 2024/12/19 01:56:37 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hixiwuz4newu': Waiting for checks to finish 2024/12/19 01:56:37 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hixiwuz4newu': Waiting for transfers to finish 2024/12/19 01:56:39 DEBUG : potato2: md5 = 944059204e4fc3c88eaaecb1dac370b3 OK 2024/12/19 01:56:39 INFO : potato2: Copied (new) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-hixiwuz4newu'", Local "Local file system at /tmp/rclone3755433712", Modify Window "1ms" --- PASS: TestCopyWithFilesFrom (3.68s) === RUN TestCopyWithFilesFromAndNoTraverse run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-hixiwuz4newu'", Local "Local file system at /tmp/rclone3755433712", Modify Window "1ms" 2024/12/19 01:56:41 DEBUG : potato2: Need to transfer - File not found at Destination 2024/12/19 01:56:41 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hixiwuz4newu': Waiting for checks to finish 2024/12/19 01:56:41 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hixiwuz4newu': Waiting for transfers to finish 2024/12/19 01:56:43 DEBUG : potato2: md5 = 367afb4307b7767cc74b3aed85f86a10 OK 2024/12/19 01:56:43 INFO : potato2: Copied (new) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-hixiwuz4newu'", Local "Local file system at /tmp/rclone3755433712", Modify Window "1ms" --- PASS: TestCopyWithFilesFromAndNoTraverse (3.79s) === RUN TestCopyEmptyDirectories run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-hixiwuz4newu'", Local "Local file system at /tmp/rclone3755433712", Modify Window "1ms" 2024/12/19 01:56:45 DEBUG : sub dir2/sub sub dir2: Making directory with metadata 2024/12/19 01:56:45 INFO : sub dir2/sub sub dir2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2024/12/19 01:56:45 INFO : sub dir2: Set directory modification time (using DirSetModTime) 2024/12/19 01:56:45 INFO : sub dir: Set directory modification time (using DirSetModTime) 2024/12/19 01:56:45 DEBUG : sub dir: Making directory with metadata 2024/12/19 01:56:46 INFO : sub dir: Made directory with metadata (mtime=2001-02-03T04:05:06.499999999Z) 2024/12/19 01:56:46 DEBUG : sub dir2: Making directory with metadata 2024/12/19 01:56:47 INFO : sub dir2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2024/12/19 01:56:47 DEBUG : sub dir2/sub sub dir2: Making directory with metadata 2024/12/19 01:56:47 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2024/12/19 01:56:48 INFO : sub dir2/sub sub dir2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2024/12/19 01:56:48 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hixiwuz4newu': Waiting for checks to finish 2024/12/19 01:56:48 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hixiwuz4newu': Waiting for transfers to finish 2024/12/19 01:56:49 DEBUG : sub dir/hello world: md5 = 52bdf1e919623d040d060e7d087492a0 OK 2024/12/19 01:56:49 INFO : sub dir/hello world: Copied (new) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-hixiwuz4newu'", Local "Local file system at /tmp/rclone3755433712", Modify Window "1ms" 2024/12/19 01:56:53 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc: Rmdir: contains trashed file: "cv6a9uf28ngrajena8kt5ijjn0" 2024/12/19 01:56:54 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestCopyEmptyDirectories (10.26s) === RUN TestCopyNoEmptyDirectories run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-hixiwuz4newu'", Local "Local file system at /tmp/rclone3755433712", Modify Window "1ms" 2024/12/19 01:56:55 DEBUG : sub dir2: Making directory 2024/12/19 01:56:55 DEBUG : sub dir2/sub sub dir2: Making directory with metadata 2024/12/19 01:56:55 INFO : sub dir2/sub sub dir2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2024/12/19 01:56:55 DEBUG : Added delayed dir = "sub dir", newDst= 2024/12/19 01:56:55 DEBUG : Added delayed dir = "sub dir2", newDst= 2024/12/19 01:56:55 DEBUG : Added delayed dir = "sub dir2/sub sub dir2", newDst= 2024/12/19 01:56:55 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2024/12/19 01:56:55 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hixiwuz4newu': Waiting for checks to finish 2024/12/19 01:56:55 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hixiwuz4newu': Waiting for transfers to finish 2024/12/19 01:56:58 DEBUG : sub dir/hello world: md5 = 9607dba12855a9fb9e28ea5953cf7c78 OK 2024/12/19 01:56:58 INFO : sub dir/hello world: Copied (new) 2024/12/19 01:56:59 INFO : sub dir: Set directory modification time (using DirSetModTime) 2024/12/19 01:57:01 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestCopyNoEmptyDirectories (6.68s) === RUN TestMoveEmptyDirectories run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-hixiwuz4newu'", Local "Local file system at /tmp/rclone3755433712", Modify Window "1ms" 2024/12/19 01:57:02 DEBUG : sub dir2: Making directory with metadata 2024/12/19 01:57:02 INFO : sub dir2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2024/12/19 01:57:02 DEBUG : sub dir: Making directory with metadata 2024/12/19 01:57:03 INFO : sub dir: Made directory with metadata (mtime=2024-12-19T01:57:02.088793294Z) 2024/12/19 01:57:03 DEBUG : sub dir2: Making directory with metadata 2024/12/19 01:57:04 INFO : sub dir2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2024/12/19 01:57:04 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2024/12/19 01:57:04 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hixiwuz4newu': Waiting for checks to finish 2024/12/19 01:57:04 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hixiwuz4newu': Waiting for transfers to finish 2024/12/19 01:57:06 DEBUG : sub dir/hello world: md5 = f80764c159383c799da3ed7032932bb2 OK 2024/12/19 01:57:06 INFO : sub dir/hello world: Copied (new) 2024/12/19 01:57:06 INFO : sub dir/hello world: Deleted run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-hixiwuz4newu'", Local "Local file system at /tmp/rclone3755433712", Modify Window "1ms" 2024/12/19 01:57:09 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestMoveEmptyDirectories (8.65s) === RUN TestSyncNoUpdateDirModtime run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-hixiwuz4newu'", Local "Local file system at /tmp/rclone3755433712", Modify Window "1ms" 2024/12/19 01:57:10 DEBUG : sub dir no update dir modtime: Making directory with metadata 2024/12/19 01:57:10 INFO : sub dir no update dir modtime: Made directory with metadata (mtime=2001-02-03T04:05:06.499999999Z) 2024/12/19 01:57:12 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hixiwuz4newu': Waiting for checks to finish 2024/12/19 01:57:12 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hixiwuz4newu': Waiting for transfers to finish 2024/12/19 01:57:12 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-hixiwuz4newu'", Local "Local file system at /tmp/rclone3755433712", Modify Window "1ms" --- PASS: TestSyncNoUpdateDirModtime (4.36s) === RUN TestMoveNoEmptyDirectories run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-hixiwuz4newu'", Local "Local file system at /tmp/rclone3755433712", Modify Window "1ms" 2024/12/19 01:57:15 DEBUG : sub dir2: Making directory 2024/12/19 01:57:15 DEBUG : Added delayed dir = "sub dir", newDst= 2024/12/19 01:57:15 DEBUG : Added delayed dir = "sub dir2", newDst= 2024/12/19 01:57:15 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2024/12/19 01:57:15 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hixiwuz4newu': Waiting for checks to finish 2024/12/19 01:57:15 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hixiwuz4newu': Waiting for transfers to finish 2024/12/19 01:57:18 DEBUG : sub dir/hello world: md5 = 7b2b2e94451122368f063a0fc1c82059 OK 2024/12/19 01:57:18 INFO : sub dir/hello world: Copied (new) 2024/12/19 01:57:18 INFO : sub dir/hello world: Deleted 2024/12/19 01:57:18 INFO : sub dir: Set directory modification time (using DirSetModTime) 2024/12/19 01:57:20 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestMoveNoEmptyDirectories (6.12s) === RUN TestSyncEmptyDirectories run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-hixiwuz4newu'", Local "Local file system at /tmp/rclone3755433712", Modify Window "1ms" 2024/12/19 01:57:21 DEBUG : sub dir2: Making directory with metadata 2024/12/19 01:57:21 INFO : sub dir2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2024/12/19 01:57:21 INFO : sub dir: Set directory modification time (using DirSetModTime) 2024/12/19 01:57:21 DEBUG : sub dir: Making directory with metadata 2024/12/19 01:57:22 INFO : sub dir: Made directory with metadata (mtime=2001-02-03T04:05:06.499999999Z) 2024/12/19 01:57:22 DEBUG : sub dir2: Making directory with metadata 2024/12/19 01:57:23 INFO : sub dir2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2024/12/19 01:57:23 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2024/12/19 01:57:23 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hixiwuz4newu': Waiting for checks to finish 2024/12/19 01:57:23 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hixiwuz4newu': Waiting for transfers to finish 2024/12/19 01:57:25 DEBUG : sub dir/hello world: md5 = 1a875d581dbb3ccada9147e2db2f97f9 OK 2024/12/19 01:57:25 INFO : sub dir/hello world: Copied (new) 2024/12/19 01:57:25 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-hixiwuz4newu'", Local "Local file system at /tmp/rclone3755433712", Modify Window "1ms" 2024/12/19 01:57:28 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestSyncEmptyDirectories (8.44s) === RUN TestSyncSetDelayedModTimes run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-hixiwuz4newu'", Local "Local file system at /tmp/rclone3755433712", 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-hixiwuz4newu'", Local "Local file system at /tmp/rclone3755433712", Modify Window "1ms" 2024/12/19 01:57:30 DEBUG : sub dir2: Making directory 2024/12/19 01:57:30 DEBUG : Added delayed dir = "sub dir", newDst= 2024/12/19 01:57:30 DEBUG : Added delayed dir = "sub dir2", newDst= 2024/12/19 01:57:30 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2024/12/19 01:57:30 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hixiwuz4newu': Waiting for checks to finish 2024/12/19 01:57:30 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hixiwuz4newu': Waiting for transfers to finish 2024/12/19 01:57:33 DEBUG : sub dir/hello world: md5 = 61d815c57d520024f2aeff50907da481 OK 2024/12/19 01:57:33 INFO : sub dir/hello world: Copied (new) 2024/12/19 01:57:33 DEBUG : Waiting for deletions to finish 2024/12/19 01:57:33 INFO : sub dir: Set directory modification time (using DirSetModTime) 2024/12/19 01:57:35 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestSyncNoEmptyDirectories (6.21s) === RUN TestServerSideCopy run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-hixiwuz4newu'", Local "Local file system at /tmp/rclone3755433712", Modify Window "1ms" 2024/12/19 01:57:39 DEBUG : sub dir/hello world: md5 = cc6de0d2a983974528642ce865a45aa5 OK 2024/12/19 01:57:39 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-viwiwac9pelu" 2024/12/19 01:57:39 DEBUG : Config file has changed externally - reloading 2024/12/19 01:57:39 DEBUG : Creating backend with remote "TestDrive:crypt/54v0907qo5vq72bb18qurqvq50m1me55qm7far5ep3s8j3q5j6pg" sync_test.go:590: Server side copy (if possible) Encrypted drive 'TestCryptDrive:rclone-test-hixiwuz4newu' -> Encrypted drive 'TestCryptDrive:rclone-test-viwiwac9pelu' 2024/12/19 01:57:41 DEBUG : Added delayed dir = "sub dir", newDst= 2024/12/19 01:57:41 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2024/12/19 01:57:41 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-viwiwac9pelu': Waiting for checks to finish 2024/12/19 01:57:41 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-viwiwac9pelu': Waiting for transfers to finish 2024/12/19 01:57:44 INFO : sub dir/hello world: Copied (server-side copy) 2024/12/19 01:57:45 INFO : sub dir: Set directory modification time (using DirSetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-hixiwuz4newu'", Local "Local file system at /tmp/rclone3755433712", Modify Window "1ms" 2024/12/19 01:57:45 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-viwiwac9pelu': Purge remote 2024/12/19 01:57:47 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestServerSideCopy (12.77s) === RUN TestCopyOverSelf run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-hixiwuz4newu'", Local "Local file system at /tmp/rclone3755433712", Modify Window "1ms" 2024/12/19 01:57:51 DEBUG : sub dir/hello world: md5 = 9f34a2359614e1f230c387ece1cb2cad OK 2024/12/19 01:57:52 DEBUG : Added delayed dir = "sub dir", newDst=sub dir 2024/12/19 01:57:52 DEBUG : sub dir/hello world: Sizes differ (src 17 vs dst 11) 2024/12/19 01:57:52 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hixiwuz4newu': Waiting for checks to finish 2024/12/19 01:57:52 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hixiwuz4newu': Waiting for transfers to finish 2024/12/19 01:57:54 DEBUG : sub dir/hello world: md5 = 24a8854da972c64f5767d29992b6934a OK 2024/12/19 01:57:54 INFO : sub dir/hello world: Copied (replaced existing) 2024/12/19 01:57:54 INFO : sub dir: Set directory modification time (using SetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-hixiwuz4newu'", Local "Local file system at /tmp/rclone3755433712", Modify Window "1ms" 2024/12/19 01:57:56 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestCopyOverSelf (8.96s) === RUN TestServerSideCopyOverSelf run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-hixiwuz4newu'", Local "Local file system at /tmp/rclone3755433712", Modify Window "1ms" 2024/12/19 01:58:00 DEBUG : sub dir/hello world: md5 = 21f8783e9b453d893b0589c8395bcf5b OK 2024/12/19 01:58:01 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-kukigeg3yoqu" 2024/12/19 01:58:01 DEBUG : Creating backend with remote "TestDrive:crypt/28ilj8b5gbjm7afpk06617m2hqpjjcth66h2bdqcpnqlgp6glhk0" sync_test.go:626: Server side copy (if possible) Encrypted drive 'TestCryptDrive:rclone-test-hixiwuz4newu' -> Encrypted drive 'TestCryptDrive:rclone-test-kukigeg3yoqu' 2024/12/19 01:58:02 DEBUG : Added delayed dir = "sub dir", newDst= 2024/12/19 01:58:02 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2024/12/19 01:58:02 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-kukigeg3yoqu': Waiting for checks to finish 2024/12/19 01:58:02 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-kukigeg3yoqu': Waiting for transfers to finish 2024/12/19 01:58:06 INFO : sub dir/hello world: Copied (server-side copy) 2024/12/19 01:58:07 INFO : sub dir: Set directory modification time (using DirSetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-hixiwuz4newu'", Local "Local file system at /tmp/rclone3755433712", Modify Window "1ms" 2024/12/19 01:58:09 DEBUG : sub dir/hello world: md5 = 15d4ea24a0580ca7e6ef8f665e68496a OK 2024/12/19 01:58:10 DEBUG : sub dir: Directory modification time the same (differ by 0s, within tolerance 1ms) 2024/12/19 01:58:10 DEBUG : Added delayed dir = "sub dir", newDst=sub dir 2024/12/19 01:58:10 DEBUG : sub dir/hello world: Sizes differ (src 17 vs dst 11) 2024/12/19 01:58:10 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-kukigeg3yoqu': Waiting for checks to finish 2024/12/19 01:58:10 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-kukigeg3yoqu': Waiting for transfers to finish 2024/12/19 01:58:12 INFO : sub dir/hello world: Copied (server-side copy) 2024/12/19 01:58:12 INFO : sub dir: Set directory modification time (using SetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-hixiwuz4newu'", Local "Local file system at /tmp/rclone3755433712", Modify Window "1ms" 2024/12/19 01:58:13 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-kukigeg3yoqu': Purge remote 2024/12/19 01:58:15 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestServerSideCopyOverSelf (19.13s) === RUN TestMoveOverSelf run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-hixiwuz4newu'", Local "Local file system at /tmp/rclone3755433712", Modify Window "1ms" 2024/12/19 01:58:19 DEBUG : sub dir/hello world: md5 = c8171e66f04d1a6ac607f850e4badd58 OK 2024/12/19 01:58:20 DEBUG : Added delayed dir = "sub dir", newDst=sub dir 2024/12/19 01:58:20 DEBUG : sub dir/hello world: Sizes differ (src 17 vs dst 11) 2024/12/19 01:58:20 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hixiwuz4newu': Waiting for checks to finish 2024/12/19 01:58:20 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hixiwuz4newu': Waiting for transfers to finish 2024/12/19 01:58:21 DEBUG : sub dir/hello world: md5 = 86726d9f1312d1067e842a8e8b2fd4cb OK 2024/12/19 01:58:21 INFO : sub dir/hello world: Copied (replaced existing) 2024/12/19 01:58:21 INFO : sub dir/hello world: Deleted 2024/12/19 01:58:22 INFO : sub dir: Set directory modification time (using SetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-hixiwuz4newu'", Local "Local file system at /tmp/rclone3755433712", Modify Window "1ms" 2024/12/19 01:58:24 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestMoveOverSelf (8.75s) === RUN TestServerSideMoveOverSelf run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-hixiwuz4newu'", Local "Local file system at /tmp/rclone3755433712", Modify Window "1ms" 2024/12/19 01:58:28 DEBUG : sub dir/hello world: md5 = 66d367079bc0d405a11359a6b1654d83 OK 2024/12/19 01:58:29 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-nenujat2wovi" 2024/12/19 01:58:29 DEBUG : Creating backend with remote "TestDrive:crypt/k7ep602ij7rtfqc2mg3rfmrljcfgmhkcl0mb42luq3mvbl468ibg" sync_test.go:671: Server side copy (if possible) Encrypted drive 'TestCryptDrive:rclone-test-hixiwuz4newu' -> Encrypted drive 'TestCryptDrive:rclone-test-nenujat2wovi' 2024/12/19 01:58:30 DEBUG : Added delayed dir = "sub dir", newDst= 2024/12/19 01:58:30 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2024/12/19 01:58:30 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-nenujat2wovi': Waiting for checks to finish 2024/12/19 01:58:30 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-nenujat2wovi': Waiting for transfers to finish 2024/12/19 01:58:33 INFO : sub dir/hello world: Copied (server-side copy) 2024/12/19 01:58:34 INFO : sub dir: Set directory modification time (using DirSetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-hixiwuz4newu'", Local "Local file system at /tmp/rclone3755433712", Modify Window "1ms" 2024/12/19 01:58:36 DEBUG : sub dir/hello world: md5 = 38528c1fe8af4d8bd70bbb71907b5e63 OK 2024/12/19 01:58:37 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-nenujat2wovi': Using server-side directory move 2024/12/19 01:58:37 INFO : Encrypted drive 'TestCryptDrive:rclone-test-nenujat2wovi': Server side directory move failed - fallback to file moves: can't copy directory - destination already exists 2024/12/19 01:58:37 DEBUG : sub dir: Directory modification time the same (differ by 0s, within tolerance 1ms) 2024/12/19 01:58:37 DEBUG : Added delayed dir = "sub dir", newDst=sub dir 2024/12/19 01:58:37 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-nenujat2wovi': Waiting for checks to finish 2024/12/19 01:58:37 DEBUG : sub dir/hello world: Sizes differ (src 17 vs dst 11) 2024/12/19 01:58:37 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-nenujat2wovi': Waiting for transfers to finish 2024/12/19 01:58:38 INFO : sub dir/hello world: Deleted 2024/12/19 01:58:38 INFO : sub dir/hello world: Moved (server-side) 2024/12/19 01:58:39 INFO : sub dir: Set directory modification time (using SetModTime) 2024/12/19 01:58:42 DEBUG : sub dir/hello world: md5 = 89d02357932d97dbcc50276be7f47358 OK 2024/12/19 01:58:42 DEBUG : testing file moves 2024/12/19 01:58:42 DEBUG : sub dir: Directory modification time the same (differ by 0s, within tolerance 1ms) 2024/12/19 01:58:42 DEBUG : Added delayed dir = "sub dir", newDst=sub dir 2024/12/19 01:58:43 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-nenujat2wovi': Waiting for checks to finish 2024/12/19 01:58:43 DEBUG : sub dir/hello world: Sizes differ (src 24 vs dst 17) 2024/12/19 01:58:43 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-nenujat2wovi': Waiting for transfers to finish 2024/12/19 01:58:43 INFO : sub dir/hello world: Deleted 2024/12/19 01:58:44 INFO : sub dir/hello world: Moved (server-side) 2024/12/19 01:58:45 INFO : sub dir: Set directory modification time (using SetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-hixiwuz4newu'", Local "Local file system at /tmp/rclone3755433712", Modify Window "1ms" 2024/12/19 01:58:46 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-nenujat2wovi': Purge remote --- PASS: TestServerSideMoveOverSelf (23.50s) === RUN TestCopyAfterDelete run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-hixiwuz4newu'", Local "Local file system at /tmp/rclone3755433712", Modify Window "1ms" 2024/12/19 01:58:52 DEBUG : sub dir/hello world: md5 = 13366da3fb40e2696c4aa7455f6e0dda OK 2024/12/19 01:58:52 ERROR : : error listing: directory not found 2024/12/19 01:58:52 DEBUG : Local file system at /tmp/rclone3755433712: Making directory 2024/12/19 01:58:53 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hixiwuz4newu': Waiting for checks to finish 2024/12/19 01:58:53 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hixiwuz4newu': Waiting for transfers to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-hixiwuz4newu'", Local "Local file system at /tmp/rclone3755433712", Modify Window "1ms" 2024/12/19 01:58:55 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestCopyAfterDelete (6.97s) === RUN TestCopyRedownload run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-hixiwuz4newu'", Local "Local file system at /tmp/rclone3755433712", Modify Window "1ms" 2024/12/19 01:58:59 DEBUG : sub dir/hello world: md5 = 4df76e585569cf5826f18219c7fd1226 OK 2024/12/19 01:59:00 DEBUG : Added delayed dir = "sub dir", newDst= 2024/12/19 01:59:00 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2024/12/19 01:59:00 DEBUG : Local file system at /tmp/rclone3755433712: Waiting for checks to finish 2024/12/19 01:59:00 DEBUG : Local file system at /tmp/rclone3755433712: Waiting for transfers to finish 2024/12/19 01:59:01 DEBUG : sub dir/hello world.285f0a30.partial: renamed to: sub dir/hello world 2024/12/19 01:59:01 INFO : sub dir/hello world: Copied (new) 2024/12/19 01:59:01 INFO : sub dir: Set directory modification time (using DirSetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-hixiwuz4newu'", Local "Local file system at /tmp/rclone3755433712", Modify Window "1ms" 2024/12/19 01:59:02 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestCopyRedownload (7.63s) === RUN TestSyncBasedOnCheckSum run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-hixiwuz4newu'", Local "Local file system at /tmp/rclone3755433712", Modify Window "1ms" 2024/12/19 01:59:04 DEBUG : check sum: Need to transfer - File not found at Destination 2024/12/19 01:59:04 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hixiwuz4newu': Waiting for checks to finish 2024/12/19 01:59:04 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hixiwuz4newu': Waiting for transfers to finish 2024/12/19 01:59:05 DEBUG : check sum: md5 = 3964ff4e0035730aaaf16df09abcceb6 OK 2024/12/19 01:59:05 INFO : check sum: Copied (new) 2024/12/19 01:59:05 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-hixiwuz4newu'", Local "Local file system at /tmp/rclone3755433712", Modify Window "1ms" 2024/12/19 01:59:06 NOTICE: Encrypted drive 'TestCryptDrive:rclone-test-hixiwuz4newu': --checksum is in use but the source and destination have no hashes in common; falling back to --size-only 2024/12/19 01:59:06 DEBUG : check sum: Size of src and dst objects identical 2024/12/19 01:59:06 DEBUG : check sum: Unchanged skipping 2024/12/19 01:59:06 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hixiwuz4newu': Waiting for checks to finish 2024/12/19 01:59:06 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hixiwuz4newu': Waiting for transfers to finish 2024/12/19 01:59:06 DEBUG : Waiting for deletions to finish 2024/12/19 01:59:06 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-hixiwuz4newu'", Local "Local file system at /tmp/rclone3755433712", Modify Window "1ms" --- PASS: TestSyncBasedOnCheckSum (4.63s) === RUN TestSyncSizeOnly run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-hixiwuz4newu'", Local "Local file system at /tmp/rclone3755433712", Modify Window "1ms" 2024/12/19 01:59:08 DEBUG : sizeonly: Need to transfer - File not found at Destination 2024/12/19 01:59:08 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hixiwuz4newu': Waiting for checks to finish 2024/12/19 01:59:08 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hixiwuz4newu': Waiting for transfers to finish 2024/12/19 01:59:10 DEBUG : sizeonly: md5 = f1718164e6369eca3815ed03ccac2eed OK 2024/12/19 01:59:10 INFO : sizeonly: Copied (new) 2024/12/19 01:59:10 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-hixiwuz4newu'", Local "Local file system at /tmp/rclone3755433712", Modify Window "1ms" 2024/12/19 01:59:11 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hixiwuz4newu': Waiting for checks to finish 2024/12/19 01:59:11 DEBUG : sizeonly: Sizes identical 2024/12/19 01:59:11 DEBUG : sizeonly: Unchanged skipping 2024/12/19 01:59:11 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hixiwuz4newu': Waiting for transfers to finish 2024/12/19 01:59:11 DEBUG : Waiting for deletions to finish 2024/12/19 01:59:11 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-hixiwuz4newu'", Local "Local file system at /tmp/rclone3755433712", Modify Window "1ms" --- PASS: TestSyncSizeOnly (4.83s) === RUN TestSyncIgnoreSize run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-hixiwuz4newu'", Local "Local file system at /tmp/rclone3755433712", Modify Window "1ms" 2024/12/19 01:59:13 DEBUG : ignore-size: Need to transfer - File not found at Destination 2024/12/19 01:59:13 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hixiwuz4newu': Waiting for checks to finish 2024/12/19 01:59:13 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hixiwuz4newu': Waiting for transfers to finish 2024/12/19 01:59:15 DEBUG : ignore-size: md5 = 741ef869f967245ab1b96e3c3121b516 OK 2024/12/19 01:59:15 INFO : ignore-size: Copied (new) 2024/12/19 01:59:15 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-hixiwuz4newu'", Local "Local file system at /tmp/rclone3755433712", Modify Window "1ms" 2024/12/19 01:59:16 DEBUG : ignore-size: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2024/12/19 01:59:16 DEBUG : ignore-size: Unchanged skipping 2024/12/19 01:59:16 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hixiwuz4newu': Waiting for checks to finish 2024/12/19 01:59:16 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hixiwuz4newu': Waiting for transfers to finish 2024/12/19 01:59:16 DEBUG : Waiting for deletions to finish 2024/12/19 01:59:16 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-hixiwuz4newu'", Local "Local file system at /tmp/rclone3755433712", Modify Window "1ms" --- PASS: TestSyncIgnoreSize (4.75s) === RUN TestSyncIgnoreTimes run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-hixiwuz4newu'", Local "Local file system at /tmp/rclone3755433712", Modify Window "1ms" 2024/12/19 01:59:20 DEBUG : existing: md5 = 086593f27369ee300c594a368d1e4197 OK 2024/12/19 01:59:20 DEBUG : existing: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2024/12/19 01:59:20 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hixiwuz4newu': Waiting for checks to finish 2024/12/19 01:59:20 DEBUG : existing: Unchanged skipping 2024/12/19 01:59:20 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hixiwuz4newu': Waiting for transfers to finish 2024/12/19 01:59:20 DEBUG : Waiting for deletions to finish 2024/12/19 01:59:20 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-hixiwuz4newu'", Local "Local file system at /tmp/rclone3755433712", Modify Window "1ms" 2024/12/19 01:59:20 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hixiwuz4newu': Waiting for checks to finish 2024/12/19 01:59:20 DEBUG : existing: Transferring unconditionally as --ignore-times is in use 2024/12/19 01:59:20 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hixiwuz4newu': Waiting for transfers to finish 2024/12/19 01:59:22 DEBUG : existing: md5 = 3e91da2855040a94397c9d14c17630f0 OK 2024/12/19 01:59:22 INFO : existing: Copied (replaced existing) 2024/12/19 01:59:22 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-hixiwuz4newu'", Local "Local file system at /tmp/rclone3755433712", Modify Window "1ms" --- PASS: TestSyncIgnoreTimes (6.26s) === RUN TestSyncIgnoreExisting run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-hixiwuz4newu'", Local "Local file system at /tmp/rclone3755433712", Modify Window "1ms" 2024/12/19 01:59:24 DEBUG : existing: Need to transfer - File not found at Destination 2024/12/19 01:59:24 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hixiwuz4newu': Waiting for checks to finish 2024/12/19 01:59:24 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hixiwuz4newu': Waiting for transfers to finish 2024/12/19 01:59:26 DEBUG : existing: md5 = 607424bb93903006510a011cae743314 OK 2024/12/19 01:59:26 INFO : existing: Copied (new) 2024/12/19 01:59:26 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-hixiwuz4newu'", Local "Local file system at /tmp/rclone3755433712", Modify Window "1ms" 2024/12/19 01:59:26 DEBUG : existing: Destination exists, skipping 2024/12/19 01:59:26 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hixiwuz4newu': Waiting for checks to finish 2024/12/19 01:59:26 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hixiwuz4newu': Waiting for transfers to finish 2024/12/19 01:59:26 DEBUG : Waiting for deletions to finish 2024/12/19 01:59:26 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-hixiwuz4newu'", Local "Local file system at /tmp/rclone3755433712", Modify Window "1ms" --- PASS: TestSyncIgnoreExisting (4.54s) === RUN TestSyncIgnoreErrors run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-hixiwuz4newu'", Local "Local file system at /tmp/rclone3755433712", Modify Window "1ms" 2024/12/19 01:59:31 DEBUG : b/potato: md5 = 66d34ee21e14616fc49fb27fbaa6f31c OK 2024/12/19 01:59:34 DEBUG : c/non empty space: md5 = 75e1c238a8e34f64ce3528d6ca68730b OK 2024/12/19 01:59:34 DEBUG : d: Making directory 2024/12/19 01:59:36 DEBUG : Added delayed dir = "a", newDst= 2024/12/19 01:59:36 DEBUG : Added delayed dir = "c", newDst=c 2024/12/19 01:59:36 DEBUG : a/potato2: Need to transfer - File not found at Destination 2024/12/19 01:59:36 DEBUG : c/non empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2024/12/19 01:59:36 DEBUG : c/non empty space: Unchanged skipping 2024/12/19 01:59:37 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hixiwuz4newu': Waiting for checks to finish 2024/12/19 01:59:37 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hixiwuz4newu': Waiting for transfers to finish 2024/12/19 01:59:39 DEBUG : a/potato2: md5 = aaa01bd51558f92ad5eda39f2968e67f OK 2024/12/19 01:59:39 INFO : a/potato2: Copied (new) 2024/12/19 01:59:39 DEBUG : Waiting for deletions to finish 2024/12/19 01:59:39 INFO : b/potato: Deleted 2024/12/19 01:59:40 INFO : a: Set directory modification time (using DirSetModTime) 2024/12/19 01:59:40 INFO : d: Removing directory 2024/12/19 01:59:41 INFO : b: Removing directory 2024/12/19 01:59:41 DEBUG : 32d8ua6196mc1r7qkfog53rkg0: Rmdir: contains trashed file: "2m507n64kafsi59v9q71r281a4" 2024/12/19 01:59:41 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hixiwuz4newu': deleted 2 directories run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-hixiwuz4newu'", Local "Local file system at /tmp/rclone3755433712", Modify Window "1ms" 2024/12/19 01:59:44 DEBUG : 3i9du405pfogq3ncai6pg7ouio: Rmdir: contains trashed file: "982d3pss7t5pn0il16r2foj31s" 2024/12/19 01:59:45 DEBUG : 2bsvlrk2ne1lfitm6tttcu0qt8: Rmdir: contains trashed file: "89l8renevh3mji1c8r1p7qn6tg" --- PASS: TestSyncIgnoreErrors (17.42s) === RUN TestSyncAfterChangingModtimeOnly run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-hixiwuz4newu'", Local "Local file system at /tmp/rclone3755433712", Modify Window "1ms" 2024/12/19 01:59:49 DEBUG : empty space: md5 = 9cf58d449a15b7fc36d56851a5bede24 OK 2024/12/19 01:59:49 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 2024/12/19 01:59:49 NOTICE: empty space: Skipped copy as --dry-run is set (size 1) 2024/12/19 01:59:49 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hixiwuz4newu': Waiting for checks to finish 2024/12/19 01:59:49 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hixiwuz4newu': Waiting for transfers to finish 2024/12/19 01:59:49 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-hixiwuz4newu'", Local "Local file system at /tmp/rclone3755433712", Modify Window "1ms" 2024/12/19 01:59:50 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hixiwuz4newu': Waiting for checks to finish 2024/12/19 01:59:50 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 2024/12/19 01:59:50 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hixiwuz4newu': Waiting for transfers to finish 2024/12/19 01:59:51 DEBUG : empty space: md5 = 134e9494e0a8ace94cc2c778643103e5 OK 2024/12/19 01:59:51 INFO : empty space: Copied (replaced existing) 2024/12/19 01:59:51 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-hixiwuz4newu'", Local "Local file system at /tmp/rclone3755433712", Modify Window "1ms" --- PASS: TestSyncAfterChangingModtimeOnly (7.14s) === RUN TestSyncAfterChangingModtimeOnlyWithNoUpdateModTime run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-hixiwuz4newu'", Local "Local file system at /tmp/rclone3755433712", Modify Window "1ms" sync_test.go:1016: Can't check this if no hashes supported --- PASS: TestSyncAfterChangingModtimeOnlyWithNoUpdateModTime (0.47s) === RUN TestSyncDoesntUpdateModtime run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-hixiwuz4newu'", Local "Local file system at /tmp/rclone3755433712", Modify Window "1ms" 2024/12/19 01:59:55 DEBUG : foo: md5 = b18ab1bf0afddf7ebe0f05fded267ff6 OK 2024/12/19 01:59:56 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hixiwuz4newu': Waiting for checks to finish 2024/12/19 01:59:56 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 2024/12/19 01:59:56 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hixiwuz4newu': Waiting for transfers to finish 2024/12/19 01:59:57 DEBUG : foo: md5 = 5558716e110d8cd1b0d558eb8a77c804 OK 2024/12/19 01:59:57 INFO : foo: Copied (replaced existing) 2024/12/19 01:59:57 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-hixiwuz4newu'", Local "Local file system at /tmp/rclone3755433712", Modify Window "1ms" --- PASS: TestSyncDoesntUpdateModtime (5.38s) === RUN TestSyncAfterAddingAFile run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-hixiwuz4newu'", Local "Local file system at /tmp/rclone3755433712", Modify Window "1ms" 2024/12/19 02:00:01 DEBUG : empty space: md5 = d61a8db4c4951f229f7819cdd70c6799 OK 2024/12/19 02:00:01 DEBUG : potato: Need to transfer - File not found at Destination 2024/12/19 02:00:01 DEBUG : empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2024/12/19 02:00:01 DEBUG : empty space: Unchanged skipping 2024/12/19 02:00:01 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hixiwuz4newu': Waiting for checks to finish 2024/12/19 02:00:01 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hixiwuz4newu': Waiting for transfers to finish 2024/12/19 02:00:03 DEBUG : potato: md5 = 3b022b88e33825a00e391e975af46ab5 OK 2024/12/19 02:00:03 INFO : potato: Copied (new) 2024/12/19 02:00:03 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-hixiwuz4newu'", Local "Local file system at /tmp/rclone3755433712", Modify Window "1ms" --- PASS: TestSyncAfterAddingAFile (6.56s) === RUN TestSyncAfterChangingFilesSizeOnly run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-hixiwuz4newu'", Local "Local file system at /tmp/rclone3755433712", Modify Window "1ms" 2024/12/19 02:00:07 DEBUG : potato: md5 = c877461a62ae3d58e7b832f661850ad4 OK 2024/12/19 02:00:08 DEBUG : potato: Sizes differ (src 21 vs dst 60) 2024/12/19 02:00:08 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hixiwuz4newu': Waiting for checks to finish 2024/12/19 02:00:08 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hixiwuz4newu': Waiting for transfers to finish 2024/12/19 02:00:09 DEBUG : potato: md5 = b34f1d14aaed276e41d76a4dbca3a161 OK 2024/12/19 02:00:09 INFO : potato: Copied (replaced existing) 2024/12/19 02:00:09 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-hixiwuz4newu'", Local "Local file system at /tmp/rclone3755433712", Modify Window "1ms" --- PASS: TestSyncAfterChangingFilesSizeOnly (5.20s) === RUN TestSyncAfterChangingContentsOnly run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-hixiwuz4newu'", Local "Local file system at /tmp/rclone3755433712", Modify Window "1ms" 2024/12/19 02:00:13 DEBUG : potato: md5 = 8743f8c19d3502d3be6e8a4f9771e095 OK 2024/12/19 02:00:13 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hixiwuz4newu': Waiting for checks to finish 2024/12/19 02:00:13 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 2024/12/19 02:00:13 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hixiwuz4newu': Waiting for transfers to finish 2024/12/19 02:00:15 DEBUG : potato: md5 = dbf90e829073370191a738e32dba202e OK 2024/12/19 02:00:15 INFO : potato: Copied (replaced existing) 2024/12/19 02:00:15 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-hixiwuz4newu'", Local "Local file system at /tmp/rclone3755433712", Modify Window "1ms" --- PASS: TestSyncAfterChangingContentsOnly (5.62s) === RUN TestSyncAfterRemovingAFileAndAddingAFileDryRun run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-hixiwuz4newu'", Local "Local file system at /tmp/rclone3755433712", Modify Window "1ms" 2024/12/19 02:00:18 DEBUG : potato: md5 = 9da8d83328631d4a250731b4e724ec2b OK 2024/12/19 02:00:20 DEBUG : empty space: md5 = 34ba550674d39248072c46b523b05c27 OK 2024/12/19 02:00:20 DEBUG : potato2: Need to transfer - File not found at Destination 2024/12/19 02:00:20 NOTICE: potato2: Skipped copy as --dry-run is set (size 60) 2024/12/19 02:00:20 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hixiwuz4newu': Waiting for checks to finish 2024/12/19 02:00:20 DEBUG : empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2024/12/19 02:00:20 DEBUG : empty space: Unchanged skipping 2024/12/19 02:00:20 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hixiwuz4newu': Waiting for transfers to finish 2024/12/19 02:00:20 DEBUG : Waiting for deletions to finish 2024/12/19 02:00:20 NOTICE: potato: Skipped delete as --dry-run is set (size 21) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-hixiwuz4newu'", Local "Local file system at /tmp/rclone3755433712", Modify Window "1ms" --- PASS: TestSyncAfterRemovingAFileAndAddingAFileDryRun (6.22s) === RUN TestSyncAfterRemovingAFileAndAddingAFile run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-hixiwuz4newu'", Local "Local file system at /tmp/rclone3755433712", Modify Window "1ms" 2024/12/19 02:00:24 DEBUG : potato: md5 = c9e987a2d09187d078cd6671505c437f OK 2024/12/19 02:00:26 DEBUG : empty space: md5 = b46ca24c334a75a66ce596aad5cdc062 OK 2024/12/19 02:00:27 DEBUG : potato2: Need to transfer - File not found at Destination 2024/12/19 02:00:27 DEBUG : empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2024/12/19 02:00:27 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hixiwuz4newu': Waiting for checks to finish 2024/12/19 02:00:27 DEBUG : empty space: Unchanged skipping 2024/12/19 02:00:27 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hixiwuz4newu': Waiting for transfers to finish 2024/12/19 02:00:28 DEBUG : potato2: md5 = 6b1c58cdeabe66c44e42a837a34509e7 OK 2024/12/19 02:00:28 INFO : potato2: Copied (new) 2024/12/19 02:00:28 DEBUG : Waiting for deletions to finish 2024/12/19 02:00:29 INFO : potato: Deleted run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-hixiwuz4newu'", Local "Local file system at /tmp/rclone3755433712", Modify Window "1ms" --- PASS: TestSyncAfterRemovingAFileAndAddingAFile (8.67s) === RUN TestSyncAfterRemovingAFileAndAddingAFileSubDir run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-hixiwuz4newu'", Local "Local file system at /tmp/rclone3755433712", Modify Window "1ms" 2024/12/19 02:00:34 DEBUG : b/potato: md5 = 5ac3ae8ceb816ae2a1f05df62473403a OK 2024/12/19 02:00:37 DEBUG : c/non empty space: md5 = 0e4ab1de25db3798b087766311c08eca OK 2024/12/19 02:00:37 DEBUG : d: Making directory 2024/12/19 02:00:38 DEBUG : d/e: Making directory 2024/12/19 02:00:40 DEBUG : Added delayed dir = "a", newDst= 2024/12/19 02:00:40 DEBUG : Added delayed dir = "c", newDst=c 2024/12/19 02:00:40 DEBUG : a/potato2: Need to transfer - File not found at Destination 2024/12/19 02:00:40 DEBUG : c/non empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2024/12/19 02:00:40 DEBUG : c/non empty space: Unchanged skipping 2024/12/19 02:00:42 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hixiwuz4newu': Waiting for checks to finish 2024/12/19 02:00:42 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hixiwuz4newu': Waiting for transfers to finish 2024/12/19 02:00:43 DEBUG : a/potato2: md5 = d8ad518634a9360532be07fc235e1008 OK 2024/12/19 02:00:43 INFO : a/potato2: Copied (new) 2024/12/19 02:00:43 DEBUG : Waiting for deletions to finish 2024/12/19 02:00:43 INFO : b/potato: Deleted 2024/12/19 02:00:44 INFO : a: Set directory modification time (using DirSetModTime) 2024/12/19 02:00:44 INFO : d/e: Removing directory 2024/12/19 02:00:45 INFO : d: Removing directory 2024/12/19 02:00:45 DEBUG : ka6id8d20d3s5ktapedlphgta8: Rmdir: contains trashed file: "r8sppajuabeak3sbgj2ak8vuf8" 2024/12/19 02:00:46 INFO : b: Removing directory 2024/12/19 02:00:46 DEBUG : 32d8ua6196mc1r7qkfog53rkg0: Rmdir: contains trashed file: "2m507n64kafsi59v9q71r281a4" 2024/12/19 02:00:46 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hixiwuz4newu': deleted 3 directories run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-hixiwuz4newu'", Local "Local file system at /tmp/rclone3755433712", Modify Window "1ms" 2024/12/19 02:00:49 DEBUG : 3i9du405pfogq3ncai6pg7ouio: Rmdir: contains trashed file: "982d3pss7t5pn0il16r2foj31s" 2024/12/19 02:00:50 DEBUG : 2bsvlrk2ne1lfitm6tttcu0qt8: Rmdir: contains trashed file: "89l8renevh3mji1c8r1p7qn6tg" --- PASS: TestSyncAfterRemovingAFileAndAddingAFileSubDir (19.95s) === RUN TestSyncAfterRemovingAFileAndAddingAFileSubDirWithErrors run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-hixiwuz4newu'", Local "Local file system at /tmp/rclone3755433712", Modify Window "1ms" 2024/12/19 02:00:54 DEBUG : b/potato: md5 = 54123d78289e3a0cc4ae9c757159ab33 OK 2024/12/19 02:00:56 DEBUG : c/non empty space: md5 = c1de1b2e8597a53fcda648fe5adf5db4 OK 2024/12/19 02:00:56 DEBUG : d: Making directory 2024/12/19 02:00:58 DEBUG : Added delayed dir = "a", newDst= 2024/12/19 02:00:58 DEBUG : Added delayed dir = "c", newDst=c 2024/12/19 02:00:58 DEBUG : a/potato2: Need to transfer - File not found at Destination 2024/12/19 02:00:58 DEBUG : c/non empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2024/12/19 02:00:58 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hixiwuz4newu': Waiting for checks to finish 2024/12/19 02:00:58 DEBUG : c/non empty space: Unchanged skipping 2024/12/19 02:00:58 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hixiwuz4newu': Waiting for transfers to finish 2024/12/19 02:01:01 DEBUG : a/potato2: md5 = 813fb0449ae476c4a707077dd3f7550c OK 2024/12/19 02:01:01 INFO : a/potato2: Copied (new) 2024/12/19 02:01:01 ERROR : Encrypted drive 'TestCryptDrive:rclone-test-hixiwuz4newu': not deleting files as there were IO errors 2024/12/19 02:01:02 INFO : a: Set directory modification time (using DirSetModTime) 2024/12/19 02:01:02 ERROR : Encrypted drive 'TestCryptDrive:rclone-test-hixiwuz4newu': not deleting directories as there were IO errors run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-hixiwuz4newu'", Local "Local file system at /tmp/rclone3755433712", Modify Window "1ms" 2024/12/19 02:01:05 DEBUG : 3i9du405pfogq3ncai6pg7ouio: Rmdir: contains trashed file: "982d3pss7t5pn0il16r2foj31s" 2024/12/19 02:01:06 DEBUG : 32d8ua6196mc1r7qkfog53rkg0: Rmdir: contains trashed file: "2m507n64kafsi59v9q71r281a4" 2024/12/19 02:01:07 DEBUG : 2bsvlrk2ne1lfitm6tttcu0qt8: Rmdir: contains trashed file: "89l8renevh3mji1c8r1p7qn6tg" --- PASS: TestSyncAfterRemovingAFileAndAddingAFileSubDirWithErrors (17.24s) === RUN TestSyncDeleteAfter --- PASS: TestSyncDeleteAfter (0.00s) === RUN TestSyncDeleteDuring run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-hixiwuz4newu'", Local "Local file system at /tmp/rclone3755433712", Modify Window "1ms" 2024/12/19 02:01:10 DEBUG : potato: md5 = 4c091c92f522e30871bb1793cf538292 OK 2024/12/19 02:01:12 DEBUG : empty space: md5 = 3abd54a4c7a94b8ae83f934b80315cea OK 2024/12/19 02:01:12 DEBUG : Waiting for deletions to finish 2024/12/19 02:01:12 DEBUG : potato2: Need to transfer - File not found at Destination 2024/12/19 02:01:12 DEBUG : empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2024/12/19 02:01:12 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hixiwuz4newu': Waiting for checks to finish 2024/12/19 02:01:12 DEBUG : empty space: Unchanged skipping 2024/12/19 02:01:12 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hixiwuz4newu': Waiting for transfers to finish 2024/12/19 02:01:13 INFO : potato: Deleted 2024/12/19 02:01:14 DEBUG : potato2: md5 = c629edd07ff987f7dffa90affd3392f2 OK 2024/12/19 02:01:14 INFO : potato2: Copied (new) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-hixiwuz4newu'", Local "Local file system at /tmp/rclone3755433712", Modify Window "1ms" --- PASS: TestSyncDeleteDuring (8.74s) === RUN TestSyncDeleteBefore run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-hixiwuz4newu'", Local "Local file system at /tmp/rclone3755433712", Modify Window "1ms" 2024/12/19 02:01:19 DEBUG : potato: md5 = 12bbd01dc230de7b8f1e15323feab2f9 OK 2024/12/19 02:01:21 DEBUG : empty space: md5 = 1e4a9d42284210831cf06907cca088cc OK 2024/12/19 02:01:21 DEBUG : Waiting for deletions to finish 2024/12/19 02:01:21 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hixiwuz4newu': Waiting for checks to finish 2024/12/19 02:01:21 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hixiwuz4newu': Waiting for transfers to finish 2024/12/19 02:01:22 INFO : potato: Deleted 2024/12/19 02:01:22 DEBUG : potato2: Need to transfer - File not found at Destination 2024/12/19 02:01:22 DEBUG : empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2024/12/19 02:01:22 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hixiwuz4newu': Waiting for checks to finish 2024/12/19 02:01:22 DEBUG : empty space: Unchanged skipping 2024/12/19 02:01:22 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hixiwuz4newu': Waiting for transfers to finish 2024/12/19 02:01:23 DEBUG : potato2: md5 = 84662233106d44da58347d1f949ed94a OK 2024/12/19 02:01:23 INFO : potato2: Copied (new) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-hixiwuz4newu'", Local "Local file system at /tmp/rclone3755433712", Modify Window "1ms" --- PASS: TestSyncDeleteBefore (8.67s) === RUN TestCopyDeleteBefore run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-hixiwuz4newu'", Local "Local file system at /tmp/rclone3755433712", Modify Window "1ms" 2024/12/19 02:01:28 DEBUG : potato: md5 = dab8b2686265fcad956c9c3f16416449 OK 2024/12/19 02:01:28 DEBUG : potato2: Need to transfer - File not found at Destination 2024/12/19 02:01:28 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hixiwuz4newu': Waiting for checks to finish 2024/12/19 02:01:28 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hixiwuz4newu': Waiting for transfers to finish 2024/12/19 02:01:30 DEBUG : potato2: md5 = 16f8191b69a5631134eb669c0af09fc6 OK 2024/12/19 02:01:30 INFO : potato2: Copied (new) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-hixiwuz4newu'", Local "Local file system at /tmp/rclone3755433712", Modify Window "1ms" --- PASS: TestCopyDeleteBefore (7.25s) === RUN TestSyncWithExclude run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-hixiwuz4newu'", Local "Local file system at /tmp/rclone3755433712", Modify Window "1ms" 2024/12/19 02:01:35 DEBUG : potato2: md5 = 583153920a3f233a0b3f14bfca2ac5f3 OK 2024/12/19 02:01:36 DEBUG : empty space: md5 = c797bd8daa888f4a840e6b7c7008d59e OK 2024/12/19 02:01:37 DEBUG : enormous: Excluded (Size Filter) 2024/12/19 02:01:37 DEBUG : enormous: Excluded 2024/12/19 02:01:37 DEBUG : potato2: Excluded (Size Filter) 2024/12/19 02:01:37 DEBUG : potato2: Excluded 2024/12/19 02:01:37 DEBUG : potato2: Excluded (Size Filter) 2024/12/19 02:01:37 DEBUG : potato2: Excluded 2024/12/19 02:01:37 DEBUG : empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2024/12/19 02:01:37 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hixiwuz4newu': Waiting for checks to finish 2024/12/19 02:01:37 DEBUG : empty space: Unchanged skipping 2024/12/19 02:01:37 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hixiwuz4newu': Waiting for transfers to finish 2024/12/19 02:01:37 DEBUG : Waiting for deletions to finish 2024/12/19 02:01:37 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-hixiwuz4newu'", Local "Local file system at /tmp/rclone3755433712", Modify Window "1ms" 2024/12/19 02:01:37 DEBUG : enormous: Excluded (Size Filter) 2024/12/19 02:01:37 DEBUG : enormous: Excluded 2024/12/19 02:01:37 DEBUG : potato2: Excluded (Size Filter) 2024/12/19 02:01:37 DEBUG : potato2: Excluded 2024/12/19 02:01:37 DEBUG : potato2: Excluded (Size Filter) 2024/12/19 02:01:37 DEBUG : potato2: Excluded 2024/12/19 02:01:37 DEBUG : empty space: Size and modification time the same (differ by 456.789µs, within tolerance 1ms) 2024/12/19 02:01:37 DEBUG : empty space: Unchanged skipping 2024/12/19 02:01:37 DEBUG : Local file system at /tmp/rclone3755433712: Waiting for checks to finish 2024/12/19 02:01:37 DEBUG : Local file system at /tmp/rclone3755433712: Waiting for transfers to finish 2024/12/19 02:01:37 DEBUG : Waiting for deletions to finish 2024/12/19 02:01:37 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-hixiwuz4newu'", Local "Local file system at /tmp/rclone3755433712", Modify Window "1ms" --- PASS: TestSyncWithExclude (6.91s) === RUN TestSyncWithExcludeAndDeleteExcluded run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-hixiwuz4newu'", Local "Local file system at /tmp/rclone3755433712", Modify Window "1ms" 2024/12/19 02:01:42 DEBUG : potato2: md5 = 28d07b968265a0f1713f25934cd20812 OK 2024/12/19 02:01:43 DEBUG : empty space: md5 = cbee4c2ca403133b9e013e764ead94f7 OK 2024/12/19 02:01:45 DEBUG : enormous: md5 = 017f559276a53ce18dec6d69ba664b4e OK 2024/12/19 02:01:45 DEBUG : enormous: Excluded (Size Filter) 2024/12/19 02:01:45 DEBUG : enormous: Excluded 2024/12/19 02:01:45 DEBUG : potato2: Excluded (Size Filter) 2024/12/19 02:01:45 DEBUG : potato2: Excluded 2024/12/19 02:01:45 DEBUG : empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2024/12/19 02:01:45 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hixiwuz4newu': Waiting for checks to finish 2024/12/19 02:01:45 DEBUG : empty space: Unchanged skipping 2024/12/19 02:01:45 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hixiwuz4newu': Waiting for transfers to finish 2024/12/19 02:01:45 DEBUG : Waiting for deletions to finish 2024/12/19 02:01:46 INFO : potato2: Deleted 2024/12/19 02:01:46 INFO : enormous: Deleted 2024/12/19 02:01:46 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-hixiwuz4newu'", Local "Local file system at /tmp/rclone3755433712", Modify Window "1ms" 2024/12/19 02:01:46 DEBUG : empty space: Size and modification time the same (differ by 456.789µs, within tolerance 1ms) 2024/12/19 02:01:46 DEBUG : Local file system at /tmp/rclone3755433712: Waiting for checks to finish 2024/12/19 02:01:46 DEBUG : empty space: Unchanged skipping 2024/12/19 02:01:46 DEBUG : Local file system at /tmp/rclone3755433712: Waiting for transfers to finish 2024/12/19 02:01:46 DEBUG : Waiting for deletions to finish 2024/12/19 02:01:46 INFO : enormous: Deleted 2024/12/19 02:01:46 INFO : potato2: Deleted 2024/12/19 02:01:46 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-hixiwuz4newu'", Local "Local file system at /tmp/rclone3755433712", Modify Window "1ms" --- PASS: TestSyncWithExcludeAndDeleteExcluded (8.34s) === RUN TestSyncWithUpdateOlder run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-hixiwuz4newu'", Local "Local file system at /tmp/rclone3755433712", Modify Window "1ms" 2024/12/19 02:01:50 DEBUG : one: md5 = eaa8f4c044dbe2cb7245e8b54f280624 OK 2024/12/19 02:01:52 DEBUG : two: md5 = 2518a5cc94f91e84c1b36811b384b481 OK 2024/12/19 02:01:53 DEBUG : three: md5 = 998844e18e146cace213cda053b91c1b OK 2024/12/19 02:01:55 DEBUG : four: md5 = 9236d0988e325f61869f13a427515f24 OK 2024/12/19 02:01:56 DEBUG : five: Need to transfer - File not found at Destination 2024/12/19 02:01:56 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hixiwuz4newu': Waiting for checks to finish 2024/12/19 02:01:56 DEBUG : four: Sizes differ (src 4 vs dst 8) 2024/12/19 02:01:56 DEBUG : one: Destination is newer than source, skipping 2024/12/19 02:01:56 DEBUG : three: Sizes identical 2024/12/19 02:01:56 DEBUG : four: Destination mod time is within 1s of source but files differ, transferring 2024/12/19 02:01:56 DEBUG : three: Destination mod time is within 1s of source and files identical, skipping 2024/12/19 02:01:56 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hixiwuz4newu': Waiting for transfers to finish 2024/12/19 02:01:57 DEBUG : two: md5 = 77c8946d13f1cb64c7f1b0977399fac5 OK 2024/12/19 02:01:57 INFO : two: Copied (replaced existing) 2024/12/19 02:01:57 DEBUG : four: md5 = c4d70902d7438ac13088810588371498 OK 2024/12/19 02:01:57 INFO : four: Copied (replaced existing) 2024/12/19 02:01:57 DEBUG : five: md5 = 03f66537d778f2b1c076972bb1c65c24 OK 2024/12/19 02:01:57 INFO : five: Copied (new) 2024/12/19 02:01:57 DEBUG : Waiting for deletions to finish sync_test.go:1449: Skip test with --checksum as no hashes supported --- PASS: TestSyncWithUpdateOlder (12.57s) === 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-hixiwuz4newu'", Local "Local file system at /tmp/rclone3755433712", Modify Window "1ms" sync_test.go:1538: Can track renames: false 2024/12/19 02:02:01 ERROR : Encrypted drive 'TestCryptDrive:rclone-test-hixiwuz4newu': Ignoring --track-renames as the source and destination do not have a common hash 2024/12/19 02:02:01 DEBUG : potato: Need to transfer - File not found at Destination 2024/12/19 02:02:01 DEBUG : yam: Need to transfer - File not found at Destination 2024/12/19 02:02:01 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hixiwuz4newu': Waiting for checks to finish 2024/12/19 02:02:01 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hixiwuz4newu': Waiting for transfers to finish 2024/12/19 02:02:03 DEBUG : yam: md5 = c14ff0b525fda3bd0813a0d39dc43de3 OK 2024/12/19 02:02:03 INFO : yam: Copied (new) 2024/12/19 02:02:03 DEBUG : potato: md5 = d58dc3025c3c9649d1e1085e7c382354 OK 2024/12/19 02:02:03 INFO : potato: Copied (new) 2024/12/19 02:02:03 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-hixiwuz4newu'", Local "Local file system at /tmp/rclone3755433712", Modify Window "1ms" 2024/12/19 02:02:03 ERROR : Encrypted drive 'TestCryptDrive:rclone-test-hixiwuz4newu': Ignoring --track-renames as the source and destination do not have a common hash 2024/12/19 02:02:03 DEBUG : yaml: Need to transfer - File not found at Destination 2024/12/19 02:02:03 DEBUG : potato: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2024/12/19 02:02:03 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hixiwuz4newu': Waiting for checks to finish 2024/12/19 02:02:03 DEBUG : potato: Unchanged skipping 2024/12/19 02:02:03 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hixiwuz4newu': Waiting for transfers to finish 2024/12/19 02:02:05 DEBUG : yaml: md5 = a002552974af2990510891edc6ead9e4 OK 2024/12/19 02:02:05 INFO : yaml: Copied (new) 2024/12/19 02:02:05 DEBUG : Waiting for deletions to finish 2024/12/19 02:02:06 INFO : yam: Deleted run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-hixiwuz4newu'", Local "Local file system at /tmp/rclone3755433712", Modify Window "1ms" --- PASS: TestSyncWithTrackRenames (7.62s) === RUN TestParseRenamesStrategyModtime --- PASS: TestParseRenamesStrategyModtime (0.00s) === RUN TestRenamesStrategyModtime --- PASS: TestRenamesStrategyModtime (0.00s) === RUN TestSyncWithTrackRenamesStrategyModtime run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-hixiwuz4newu'", Local "Local file system at /tmp/rclone3755433712", Modify Window "1ms" sync_test.go:1610: Can track renames: true 2024/12/19 02:02:09 INFO : Encrypted drive 'TestCryptDrive:rclone-test-hixiwuz4newu': Making map for --track-renames 2024/12/19 02:02:09 INFO : Encrypted drive 'TestCryptDrive:rclone-test-hixiwuz4newu': Finished making map for --track-renames 2024/12/19 02:02:09 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hixiwuz4newu': Waiting for checks to finish 2024/12/19 02:02:09 DEBUG : potato: Need to transfer - No matching file found at Destination 2024/12/19 02:02:09 DEBUG : yam: Need to transfer - No matching file found at Destination 2024/12/19 02:02:09 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hixiwuz4newu': Waiting for renames to finish 2024/12/19 02:02:09 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hixiwuz4newu': Waiting for transfers to finish 2024/12/19 02:02:10 DEBUG : potato: md5 = cdf17c4ec4d3b43d5b491170f3c1b0e8 OK 2024/12/19 02:02:10 INFO : potato: Copied (new) 2024/12/19 02:02:11 DEBUG : yam: md5 = 89ba271a96d8c9f64a16fe1f5c4e7277 OK 2024/12/19 02:02:11 INFO : yam: Copied (new) 2024/12/19 02:02:11 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-hixiwuz4newu'", Local "Local file system at /tmp/rclone3755433712", Modify Window "1ms" 2024/12/19 02:02:11 DEBUG : potato: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2024/12/19 02:02:11 INFO : Encrypted drive 'TestCryptDrive:rclone-test-hixiwuz4newu': Making map for --track-renames 2024/12/19 02:02:11 INFO : Encrypted drive 'TestCryptDrive:rclone-test-hixiwuz4newu': Finished making map for --track-renames 2024/12/19 02:02:11 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hixiwuz4newu': Waiting for checks to finish 2024/12/19 02:02:11 DEBUG : potato: Unchanged skipping 2024/12/19 02:02:11 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hixiwuz4newu': Waiting for renames to finish 2024/12/19 02:02:12 INFO : yam: Moved (server-side) to: yaml 2024/12/19 02:02:12 INFO : yaml: Renamed from "yam" 2024/12/19 02:02:12 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hixiwuz4newu': Waiting for transfers to finish 2024/12/19 02:02:12 DEBUG : Waiting for deletions to finish 2024/12/19 02:02:12 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-hixiwuz4newu'", Local "Local file system at /tmp/rclone3755433712", Modify Window "1ms" --- PASS: TestSyncWithTrackRenamesStrategyModtime (6.11s) === RUN TestSyncWithTrackRenamesStrategyLeaf run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-hixiwuz4newu'", Local "Local file system at /tmp/rclone3755433712", Modify Window "1ms" sync_test.go:1649: Can track renames: true 2024/12/19 02:02:15 DEBUG : Added delayed dir = "sub", newDst= 2024/12/19 02:02:15 INFO : Encrypted drive 'TestCryptDrive:rclone-test-hixiwuz4newu': Making map for --track-renames 2024/12/19 02:02:15 INFO : Encrypted drive 'TestCryptDrive:rclone-test-hixiwuz4newu': Finished making map for --track-renames 2024/12/19 02:02:15 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hixiwuz4newu': Waiting for checks to finish 2024/12/19 02:02:15 DEBUG : potato: Need to transfer - No matching file found at Destination 2024/12/19 02:02:15 DEBUG : sub/yam: Need to transfer - No matching file found at Destination 2024/12/19 02:02:15 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hixiwuz4newu': Waiting for renames to finish 2024/12/19 02:02:15 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hixiwuz4newu': Waiting for transfers to finish 2024/12/19 02:02:18 DEBUG : sub/yam: md5 = 844fa42e79d8ada13b063b4e6649a846 OK 2024/12/19 02:02:18 INFO : sub/yam: Copied (new) 2024/12/19 02:02:18 DEBUG : potato: md5 = 693f9655cf606ed99607f03c4ff1ffcd OK 2024/12/19 02:02:18 INFO : potato: Copied (new) 2024/12/19 02:02:18 DEBUG : Waiting for deletions to finish 2024/12/19 02:02:18 INFO : sub: Set directory modification time (using DirSetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-hixiwuz4newu'", Local "Local file system at /tmp/rclone3755433712", Modify Window "1ms" 2024/12/19 02:02:19 DEBUG : Added delayed dir = "sub", newDst=sub 2024/12/19 02:02:19 DEBUG : potato: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2024/12/19 02:02:19 DEBUG : potato: Unchanged skipping 2024/12/19 02:02:19 INFO : Encrypted drive 'TestCryptDrive:rclone-test-hixiwuz4newu': Making map for --track-renames 2024/12/19 02:02:19 INFO : Encrypted drive 'TestCryptDrive:rclone-test-hixiwuz4newu': Finished making map for --track-renames 2024/12/19 02:02:19 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hixiwuz4newu': Waiting for checks to finish 2024/12/19 02:02:19 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hixiwuz4newu': Waiting for renames to finish 2024/12/19 02:02:20 INFO : sub/yam: Moved (server-side) to: yam 2024/12/19 02:02:20 INFO : yam: Renamed from "sub/yam" 2024/12/19 02:02:20 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hixiwuz4newu': Waiting for transfers to finish 2024/12/19 02:02:20 DEBUG : Waiting for deletions to finish 2024/12/19 02:02:20 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-hixiwuz4newu'", Local "Local file system at /tmp/rclone3755433712", Modify Window "1ms" --- PASS: TestSyncWithTrackRenamesStrategyLeaf (9.62s) === RUN TestServerSideMoveLocal run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-hixiwuz4newu'", Local "Local file system at /tmp/rclone3755433712", Modify Window "1ms" 2024/12/19 02:02:24 DEBUG : Creating backend with remote "/tmp/rclone3755433712/dir1" 2024/12/19 02:02:24 DEBUG : Config file has changed externally - reloading 2024/12/19 02:02:24 DEBUG : Creating backend with remote "/tmp/rclone3755433712/dir2" 2024/12/19 02:02:24 DEBUG : Local file system at /tmp/rclone3755433712/dir2: Using server-side directory move 2024/12/19 02:02:24 INFO : Local file system at /tmp/rclone3755433712/dir2: Server side directory move failed - fallback to file moves: can't copy directory - destination already exists 2024/12/19 02:02:24 DEBUG : file1.txt: Need to transfer - File not found at Destination 2024/12/19 02:02:24 INFO : file1.txt: Moved (server-side) 2024/12/19 02:02:24 DEBUG : Local file system at /tmp/rclone3755433712/dir2: Waiting for checks to finish 2024/12/19 02:02:24 DEBUG : Local file system at /tmp/rclone3755433712/dir2: Waiting for transfers to finish --- PASS: TestServerSideMoveLocal (0.48s) === RUN TestMoveWithDeleteEmptySrcDirs run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-hixiwuz4newu'", Local "Local file system at /tmp/rclone3755433712", Modify Window "1ms" 2024/12/19 02:02:25 DEBUG : Added delayed dir = "nested", newDst= 2024/12/19 02:02:25 DEBUG : Added delayed dir = "sub dir", newDst= 2024/12/19 02:02:25 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2024/12/19 02:02:25 DEBUG : Added delayed dir = "nested/sub dir", newDst= 2024/12/19 02:02:25 DEBUG : nested/sub dir/file: Need to transfer - File not found at Destination 2024/12/19 02:02:25 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hixiwuz4newu': Waiting for checks to finish 2024/12/19 02:02:25 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hixiwuz4newu': Waiting for transfers to finish 2024/12/19 02:02:28 DEBUG : sub dir/hello world: md5 = 14e1cbd703361c1bf4caedfecaec7d5f OK 2024/12/19 02:02:28 INFO : sub dir/hello world: Copied (new) 2024/12/19 02:02:28 INFO : sub dir/hello world: Deleted 2024/12/19 02:02:30 DEBUG : nested/sub dir/file: md5 = 79cac655db8f3c00514cb30cb02863d1 OK 2024/12/19 02:02:30 INFO : nested/sub dir/file: Copied (new) 2024/12/19 02:02:30 INFO : nested/sub dir/file: Deleted 2024/12/19 02:02:30 INFO : nested/sub dir: Set directory modification time (using DirSetModTime) 2024/12/19 02:02:31 INFO : nested: Set directory modification time (using DirSetModTime) 2024/12/19 02:02:31 INFO : sub dir: Set directory modification time (using DirSetModTime) 2024/12/19 02:02:31 INFO : sub dir: Removing directory 2024/12/19 02:02:31 INFO : nested/sub dir: Removing directory 2024/12/19 02:02:31 INFO : nested: Removing directory 2024/12/19 02:02:31 DEBUG : Local file system at /tmp/rclone3755433712: deleted 3 directories run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-hixiwuz4newu'", Local "Local file system at /tmp/rclone3755433712", Modify Window "1ms" 2024/12/19 02:02:34 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" 2024/12/19 02:02:35 DEBUG : 37qp6d1gohacv723ij3brofbu8/14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "ftp4kuv8se7tqduu6pmmcvjsmk" 2024/12/19 02:02:35 DEBUG : 37qp6d1gohacv723ij3brofbu8: Rmdir: contains trashed file: "14begaa36ih249fgrnfk6nulg0" --- PASS: TestMoveWithDeleteEmptySrcDirs (12.08s) === RUN TestMoveWithoutDeleteEmptySrcDirs run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-hixiwuz4newu'", Local "Local file system at /tmp/rclone3755433712", Modify Window "1ms" 2024/12/19 02:02:37 DEBUG : Added delayed dir = "nested", newDst= 2024/12/19 02:02:37 DEBUG : Added delayed dir = "sub dir", newDst= 2024/12/19 02:02:37 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2024/12/19 02:02:37 DEBUG : Added delayed dir = "nested/sub dir", newDst= 2024/12/19 02:02:37 DEBUG : nested/sub dir/file: Need to transfer - File not found at Destination 2024/12/19 02:02:37 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hixiwuz4newu': Waiting for checks to finish 2024/12/19 02:02:37 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hixiwuz4newu': Waiting for transfers to finish 2024/12/19 02:02:40 DEBUG : sub dir/hello world: md5 = 171d169b7e78a5f250bcf7195e835d33 OK 2024/12/19 02:02:40 INFO : sub dir/hello world: Copied (new) 2024/12/19 02:02:40 INFO : sub dir/hello world: Deleted 2024/12/19 02:02:42 DEBUG : nested/sub dir/file: md5 = e2273e51cca09904fcd0d1cc2ec8361b OK 2024/12/19 02:02:42 INFO : nested/sub dir/file: Copied (new) 2024/12/19 02:02:42 INFO : nested/sub dir/file: Deleted 2024/12/19 02:02:43 INFO : nested/sub dir: Set directory modification time (using DirSetModTime) 2024/12/19 02:02:43 INFO : sub dir: Set directory modification time (using DirSetModTime) 2024/12/19 02:02:43 INFO : nested: Set directory modification time (using DirSetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-hixiwuz4newu'", Local "Local file system at /tmp/rclone3755433712", Modify Window "1ms" 2024/12/19 02:02:46 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" 2024/12/19 02:02:47 DEBUG : 37qp6d1gohacv723ij3brofbu8/14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "ftp4kuv8se7tqduu6pmmcvjsmk" 2024/12/19 02:02:48 DEBUG : 37qp6d1gohacv723ij3brofbu8: Rmdir: contains trashed file: "14begaa36ih249fgrnfk6nulg0" --- PASS: TestMoveWithoutDeleteEmptySrcDirs (12.07s) === RUN TestMoveWithIgnoreExisting run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-hixiwuz4newu'", Local "Local file system at /tmp/rclone3755433712", Modify Window "1ms" 2024/12/19 02:02:49 DEBUG : existing: Need to transfer - File not found at Destination 2024/12/19 02:02:49 DEBUG : existing-b: Need to transfer - File not found at Destination 2024/12/19 02:02:49 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hixiwuz4newu': Waiting for checks to finish 2024/12/19 02:02:49 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hixiwuz4newu': Waiting for transfers to finish 2024/12/19 02:02:51 DEBUG : existing: md5 = 514603c07946f429195127a34e32d491 OK 2024/12/19 02:02:51 INFO : existing: Copied (new) 2024/12/19 02:02:51 INFO : existing: Deleted 2024/12/19 02:02:51 DEBUG : existing-b: md5 = e0340072216307246d604d429b606791 OK 2024/12/19 02:02:51 INFO : existing-b: Copied (new) 2024/12/19 02:02:51 INFO : existing-b: Deleted 2024/12/19 02:02:51 DEBUG : existing: Destination exists, skipping 2024/12/19 02:02:51 DEBUG : existing: Not removing source file as destination file exists and --ignore-existing is set 2024/12/19 02:02:51 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hixiwuz4newu': Waiting for checks to finish 2024/12/19 02:02:51 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hixiwuz4newu': Waiting for transfers to finish 2024/12/19 02:02:51 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-hixiwuz4newu'", Local "Local file system at /tmp/rclone3755433712", Modify Window "1ms" --- PASS: TestMoveWithIgnoreExisting (4.83s) === RUN TestServerSideMove run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-hixiwuz4newu'", Local "Local file system at /tmp/rclone3755433712", Modify Window "1ms" 2024/12/19 02:02:54 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-jeretoy5gigo" 2024/12/19 02:02:54 DEBUG : Creating backend with remote "TestDrive:crypt/rsabp0ss4ukmi2138h3a0k6r3pkc48jg4q6mj2iddjt88p5bho4g" 2024/12/19 02:02:56 DEBUG : potato2: md5 = 1b3f2796d29c3e2b196465f345653e4a OK 2024/12/19 02:02:58 DEBUG : empty space: md5 = 689ea6833c844663f1d5892e20ddb574 OK 2024/12/19 02:02:59 DEBUG : potato3: md5 = 8845f3ea3e6040ab565082f603f7cf96 OK sync_test.go:1705: Server side move (if possible) Encrypted drive 'TestCryptDrive:rclone-test-hixiwuz4newu' -> Encrypted drive 'TestCryptDrive:rclone-test-jeretoy5gigo' 2024/12/19 02:03:03 DEBUG : empty space: md5 = 75b3f40d89424a0904521cafb455197a OK 2024/12/19 02:03:04 DEBUG : potato3: md5 = b35b1fc6abd28cd67d02c9f91ffc05ed OK 2024/12/19 02:03:04 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-jeretoy5gigo': Using server-side directory move 2024/12/19 02:03:04 INFO : Encrypted drive 'TestCryptDrive:rclone-test-jeretoy5gigo': Server side directory move failed - fallback to file moves: can't copy directory - destination already exists 2024/12/19 02:03:05 DEBUG : potato2: Need to transfer - File not found at Destination 2024/12/19 02:03:05 DEBUG : empty space: Size and modification time the same (differ by 0s, within tolerance 1ms) 2024/12/19 02:03:05 DEBUG : empty space: Unchanged skipping 2024/12/19 02:03:05 DEBUG : potato3: Sizes differ (src 68 vs dst 60) 2024/12/19 02:03:05 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-jeretoy5gigo': Waiting for checks to finish 2024/12/19 02:03:05 INFO : potato3: Deleted 2024/12/19 02:03:05 INFO : empty space: Deleted 2024/12/19 02:03:05 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-jeretoy5gigo': Waiting for transfers to finish 2024/12/19 02:03:06 INFO : potato2: Moved (server-side) 2024/12/19 02:03:06 INFO : potato3: Moved (server-side) 2024/12/19 02:03:07 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-guzalah3mobe" 2024/12/19 02:03:07 DEBUG : Creating backend with remote "TestDrive:crypt/glka2u92mk9l1h4pjo7u5l9eh6jk5alca8hf3hje6ol0o8r2bveg" 2024/12/19 02:03:08 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-guzalah3mobe': Using server-side directory move 2024/12/19 02:03:09 INFO : Encrypted drive 'TestCryptDrive:rclone-test-guzalah3mobe': Server side directory move succeeded 2024/12/19 02:03:10 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-guzalah3mobe': Purge remote 2024/12/19 02:03:11 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-jeretoy5gigo': Purge remote 2024/12/19 02:03:11 NOTICE: purge failed: directory not found --- PASS: TestServerSideMove (17.57s) === RUN TestServerSideMoveWithFilter run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-hixiwuz4newu'", Local "Local file system at /tmp/rclone3755433712", Modify Window "1ms" 2024/12/19 02:03:11 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-zoxitaf4ruka" 2024/12/19 02:03:11 DEBUG : Creating backend with remote "TestDrive:crypt/h1pkrk8js0lr9193pf95dmgc4g6mcfd7okd7fgtan95d8rtvuuk0" 2024/12/19 02:03:14 DEBUG : potato2: md5 = 334902f82b334a920abf680e93de862b OK 2024/12/19 02:03:16 DEBUG : empty space: md5 = 02686bb5412b68bcd4ed765d127b0ba5 OK 2024/12/19 02:03:17 DEBUG : potato3: md5 = 7be6e9fc954487b0c0fc386c57c3abf7 OK sync_test.go:1705: Server side move (if possible) Encrypted drive 'TestCryptDrive:rclone-test-hixiwuz4newu' -> Encrypted drive 'TestCryptDrive:rclone-test-zoxitaf4ruka' 2024/12/19 02:03:20 DEBUG : empty space: md5 = f83a0a561746d0e10549839582086af1 OK 2024/12/19 02:03:22 DEBUG : potato3: md5 = 3ce52a0b0a39babbb6571692af833639 OK 2024/12/19 02:03:22 DEBUG : empty space: Excluded (Size Filter) 2024/12/19 02:03:22 DEBUG : empty space: Excluded 2024/12/19 02:03:22 DEBUG : empty space: Excluded (Size Filter) 2024/12/19 02:03:22 DEBUG : empty space: Excluded 2024/12/19 02:03:22 DEBUG : potato2: Need to transfer - File not found at Destination 2024/12/19 02:03:22 DEBUG : potato3: Sizes differ (src 68 vs dst 60) 2024/12/19 02:03:22 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zoxitaf4ruka': Waiting for checks to finish 2024/12/19 02:03:22 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zoxitaf4ruka': Waiting for transfers to finish 2024/12/19 02:03:23 INFO : potato3: Deleted 2024/12/19 02:03:23 INFO : potato2: Moved (server-side) 2024/12/19 02:03:24 INFO : potato3: Moved (server-side) 2024/12/19 02:03:24 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-muweduf8livi" 2024/12/19 02:03:24 DEBUG : Config file has changed externally - reloading 2024/12/19 02:03:24 DEBUG : Creating backend with remote "TestDrive:crypt/h1m0atehu5aknvrakhvu18juucvlm2sujr9sniqmf0l3t35rc7p0" 2024/12/19 02:03:26 DEBUG : empty space: Excluded (Size Filter) 2024/12/19 02:03:26 DEBUG : empty space: Excluded 2024/12/19 02:03:26 DEBUG : potato2: Need to transfer - File not found at Destination 2024/12/19 02:03:26 DEBUG : potato3: Need to transfer - File not found at Destination 2024/12/19 02:03:26 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-muweduf8livi': Waiting for checks to finish 2024/12/19 02:03:26 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-muweduf8livi': Waiting for transfers to finish 2024/12/19 02:03:28 INFO : potato2: Moved (server-side) 2024/12/19 02:03:28 INFO : potato3: Moved (server-side) 2024/12/19 02:03:29 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-muweduf8livi': Purge remote 2024/12/19 02:03:29 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zoxitaf4ruka': Purge remote --- PASS: TestServerSideMoveWithFilter (19.53s) === RUN TestServerSideMoveDeleteEmptySourceDirs run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-hixiwuz4newu'", Local "Local file system at /tmp/rclone3755433712", Modify Window "1ms" 2024/12/19 02:03:31 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-lotivex4soxi" 2024/12/19 02:03:31 DEBUG : Creating backend with remote "TestDrive:crypt/oei5thsfaflf0crllpria2f4utdla3ohv17kvotenmiff4as0ogg" 2024/12/19 02:03:34 DEBUG : potato2: md5 = 01c5717966b47ddac6122a42470613b9 OK 2024/12/19 02:03:35 DEBUG : empty space: md5 = fe6f40b49012a47f5a40871300b0fe68 OK 2024/12/19 02:03:37 DEBUG : potato3: md5 = cdfa3e5eb1b39b51f634dcfea3b7f30c OK 2024/12/19 02:03:37 DEBUG : tomatoDir: Making directory sync_test.go:1705: Server side move (if possible) Encrypted drive 'TestCryptDrive:rclone-test-hixiwuz4newu' -> Encrypted drive 'TestCryptDrive:rclone-test-lotivex4soxi' 2024/12/19 02:03:42 DEBUG : empty space: md5 = 800be549536759cb6992da3d55e779bb OK 2024/12/19 02:03:43 DEBUG : potato3: md5 = a78d6b711c2326df641b5348e8ee4173 OK 2024/12/19 02:03:43 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-lotivex4soxi': Using server-side directory move 2024/12/19 02:03:43 INFO : Encrypted drive 'TestCryptDrive:rclone-test-lotivex4soxi': Server side directory move failed - fallback to file moves: can't copy directory - destination already exists 2024/12/19 02:03:44 DEBUG : potato2: Need to transfer - File not found at Destination 2024/12/19 02:03:44 DEBUG : Added delayed dir = "tomatoDir", newDst= 2024/12/19 02:03:44 DEBUG : empty space: Size and modification time the same (differ by 0s, within tolerance 1ms) 2024/12/19 02:03:44 DEBUG : empty space: Unchanged skipping 2024/12/19 02:03:44 DEBUG : potato3: Sizes differ (src 68 vs dst 60) 2024/12/19 02:03:44 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-lotivex4soxi': Waiting for checks to finish 2024/12/19 02:03:44 INFO : potato3: Deleted 2024/12/19 02:03:44 INFO : empty space: Deleted 2024/12/19 02:03:44 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-lotivex4soxi': Waiting for transfers to finish 2024/12/19 02:03:45 INFO : potato2: Moved (server-side) 2024/12/19 02:03:46 INFO : potato3: Moved (server-side) 2024/12/19 02:03:46 INFO : tomatoDir: Removing directory 2024/12/19 02:03:47 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hixiwuz4newu': deleted 1 directories 2024/12/19 02:03:47 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-gedapib9nuji" 2024/12/19 02:03:47 DEBUG : Creating backend with remote "TestDrive:crypt/5o94103vjb6cbgicb64m0i9qes2nd6ml1ej75atcd6s7ic4lrk20" 2024/12/19 02:03:48 DEBUG : tomatoDir: Making directory 2024/12/19 02:03:49 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gedapib9nuji': Using server-side directory move 2024/12/19 02:03:50 INFO : Encrypted drive 'TestCryptDrive:rclone-test-gedapib9nuji': Server side directory move succeeded 2024/12/19 02:03:51 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-gedapib9nuji': Purge remote 2024/12/19 02:03:52 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-lotivex4soxi': Purge remote 2024/12/19 02:03:52 NOTICE: purge failed: directory not found --- PASS: TestServerSideMoveDeleteEmptySourceDirs (22.00s) === RUN TestServerSideMoveOverlap run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-hixiwuz4newu'", Local "Local file system at /tmp/rclone3755433712", Modify Window "1ms" sync_test.go:1910: Skipping test as remote supports DirMove --- SKIP: TestServerSideMoveOverlap (0.45s) === RUN TestSyncOverlap run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-hixiwuz4newu'", Local "Local file system at /tmp/rclone3755433712", Modify Window "1ms" 2024/12/19 02:03:53 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-hixiwuz4newu/rclone-sync-test" 2024/12/19 02:03:53 DEBUG : Creating backend with remote "TestDrive:crypt/migt86lmhkdmp5mgvq09tvu1uvaavurlpu91lhqg4rsp22d6epjg/i7355aa0sb89uagn75vfjqr6s3e3e1h2et8in57abn1fe8qfego0" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-hixiwuz4newu'", Local "Local file system at /tmp/rclone3755433712", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-hixiwuz4newu'", Local "Local file system at /tmp/rclone3755433712", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-hixiwuz4newu'", Local "Local file system at /tmp/rclone3755433712", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-hixiwuz4newu'", Local "Local file system at /tmp/rclone3755433712", Modify Window "1ms" --- PASS: TestSyncOverlap (3.92s) === RUN TestSyncOverlapWithFilter run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-hixiwuz4newu'", Local "Local file system at /tmp/rclone3755433712", Modify Window "1ms" 2024/12/19 02:03:57 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-hixiwuz4newu/rclone-sync-test" 2024/12/19 02:03:57 DEBUG : Creating backend with remote "TestDrive:crypt/migt86lmhkdmp5mgvq09tvu1uvaavurlpu91lhqg4rsp22d6epjg/i7355aa0sb89uagn75vfjqr6s3e3e1h2et8in57abn1fe8qfego0" 2024/12/19 02:04:00 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-hixiwuz4newu/rclone-sync-test-include/layer2" 2024/12/19 02:04:00 DEBUG : Creating backend with remote "TestDrive:crypt/migt86lmhkdmp5mgvq09tvu1uvaavurlpu91lhqg4rsp22d6epjg/khf2vlblvnbf9ftevqm0htmss73hj1j5a7q328e4ohrgs7e2loe0/n01jpl9202nn9ec1rb75h0f1c4" 2024/12/19 02:04:03 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-hixiwuz4newu/rclone-sync-test-ignore-file" 2024/12/19 02:04:03 DEBUG : Creating backend with remote "TestDrive:crypt/migt86lmhkdmp5mgvq09tvu1uvaavurlpu91lhqg4rsp22d6epjg/kmf11jujl9uha3tjganvgpkn45bu778hb5vb5riug1c26b38k7sg" 2024/12/19 02:04:08 DEBUG : rclone-sync-test-ignore-file/.ignore: md5 = 0b33f56dd0fd44d4584549405b6fd040 OK 2024/12/19 02:04:09 DEBUG : rclone-sync-test-ignore-file: Excluded 2024/12/19 02:04:09 DEBUG : rclone-sync-test: Excluded 2024/12/19 02:04:09 DEBUG : Added delayed dir = "rclone-sync-test-include", newDst= 2024/12/19 02:04:10 DEBUG : rclone-sync-test-include/layer2: Excluded 2024/12/19 02:04:10 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hixiwuz4newu/rclone-sync-test': Waiting for checks to finish 2024/12/19 02:04:10 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hixiwuz4newu/rclone-sync-test': Waiting for transfers to finish 2024/12/19 02:04:10 DEBUG : Waiting for deletions to finish 2024/12/19 02:04:10 INFO : There was nothing to transfer 2024/12/19 02:04:10 DEBUG : rclone-sync-test-ignore-file: Excluded 2024/12/19 02:04:11 DEBUG : rclone-sync-test: Excluded 2024/12/19 02:04:11 DEBUG : rclone-sync-test-include/layer2: Excluded 2024/12/19 02:04:11 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hixiwuz4newu': Waiting for checks to finish 2024/12/19 02:04:11 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hixiwuz4newu': Waiting for transfers to finish 2024/12/19 02:04:11 DEBUG : Waiting for deletions to finish 2024/12/19 02:04:11 INFO : rclone-sync-test-include: Removing directory 2024/12/19 02:04:12 DEBUG : khf2vlblvnbf9ftevqm0htmss73hj1j5a7q328e4ohrgs7e2loe0: Rmdir: contains file: "n01jpl9202nn9ec1rb75h0f1c4" 2024/12/19 02:04:12 DEBUG : rclone-sync-test-include: Failed to Rmdir: directory not empty 2024/12/19 02:04:12 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hixiwuz4newu': failed to delete 1 directories 2024/12/19 02:04:12 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-hixiwuz4newu'", Local "Local file system at /tmp/rclone3755433712", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-hixiwuz4newu'", Local "Local file system at /tmp/rclone3755433712", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-hixiwuz4newu'", Local "Local file system at /tmp/rclone3755433712", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-hixiwuz4newu'", Local "Local file system at /tmp/rclone3755433712", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-hixiwuz4newu'", Local "Local file system at /tmp/rclone3755433712", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-hixiwuz4newu'", Local "Local file system at /tmp/rclone3755433712", Modify Window "1ms" 2024/12/19 02:04:12 DEBUG : rclone-sync-test-ignore-file: Excluded 2024/12/19 02:04:13 DEBUG : rclone-sync-test: Excluded 2024/12/19 02:04:13 DEBUG : Added delayed dir = "rclone-sync-test-include", newDst= 2024/12/19 02:04:13 DEBUG : rclone-sync-test-include/layer2: Excluded 2024/12/19 02:04:13 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hixiwuz4newu/rclone-sync-test-include/layer2': Waiting for checks to finish 2024/12/19 02:04:13 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hixiwuz4newu/rclone-sync-test-include/layer2': Waiting for transfers to finish 2024/12/19 02:04:13 DEBUG : Waiting for deletions to finish 2024/12/19 02:04:13 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-hixiwuz4newu'", Local "Local file system at /tmp/rclone3755433712", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-hixiwuz4newu'", Local "Local file system at /tmp/rclone3755433712", Modify Window "1ms" 2024/12/19 02:04:14 DEBUG : rclone-sync-test-ignore-file: Excluded 2024/12/19 02:04:15 DEBUG : rclone-sync-test: Excluded 2024/12/19 02:04:15 DEBUG : rclone-sync-test-include/layer2: Excluded 2024/12/19 02:04:15 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hixiwuz4newu': Waiting for checks to finish 2024/12/19 02:04:15 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hixiwuz4newu': Waiting for transfers to finish 2024/12/19 02:04:15 DEBUG : Waiting for deletions to finish 2024/12/19 02:04:15 INFO : rclone-sync-test-include: Removing directory 2024/12/19 02:04:15 DEBUG : khf2vlblvnbf9ftevqm0htmss73hj1j5a7q328e4ohrgs7e2loe0: Rmdir: contains file: "n01jpl9202nn9ec1rb75h0f1c4" 2024/12/19 02:04:15 DEBUG : rclone-sync-test-include: Failed to Rmdir: directory not empty 2024/12/19 02:04:15 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hixiwuz4newu': failed to delete 1 directories 2024/12/19 02:04:15 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-hixiwuz4newu'", Local "Local file system at /tmp/rclone3755433712", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-hixiwuz4newu'", Local "Local file system at /tmp/rclone3755433712", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-hixiwuz4newu'", Local "Local file system at /tmp/rclone3755433712", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-hixiwuz4newu'", Local "Local file system at /tmp/rclone3755433712", Modify Window "1ms" 2024/12/19 02:04:16 DEBUG : : Excluded 2024/12/19 02:04:16 DEBUG : rclone-sync-test-ignore-file: Excluded 2024/12/19 02:04:16 DEBUG : rclone-sync-test: Excluded 2024/12/19 02:04:16 DEBUG : Added delayed dir = "rclone-sync-test-include", newDst= 2024/12/19 02:04:17 DEBUG : rclone-sync-test-include/layer2: Excluded 2024/12/19 02:04:17 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hixiwuz4newu/rclone-sync-test-ignore-file': Waiting for checks to finish 2024/12/19 02:04:17 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hixiwuz4newu/rclone-sync-test-ignore-file': Waiting for transfers to finish 2024/12/19 02:04:17 DEBUG : Waiting for deletions to finish 2024/12/19 02:04:17 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-hixiwuz4newu'", Local "Local file system at /tmp/rclone3755433712", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-hixiwuz4newu'", Local "Local file system at /tmp/rclone3755433712", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-hixiwuz4newu'", Local "Local file system at /tmp/rclone3755433712", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-hixiwuz4newu'", Local "Local file system at /tmp/rclone3755433712", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-hixiwuz4newu'", Local "Local file system at /tmp/rclone3755433712", Modify Window "1ms" 2024/12/19 02:04:19 DEBUG : khf2vlblvnbf9ftevqm0htmss73hj1j5a7q328e4ohrgs7e2loe0: Rmdir: contains trashed file: "n01jpl9202nn9ec1rb75h0f1c4" 2024/12/19 02:04:20 DEBUG : kmf11jujl9uha3tjganvgpkn45bu778hb5vb5riug1c26b38k7sg: Rmdir: contains trashed file: "i0t74httmdlljg425j6tg570d8" --- PASS: TestSyncOverlapWithFilter (32.29s) === RUN TestSyncCompareDest run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-hixiwuz4newu'", Local "Local file system at /tmp/rclone3755433712", Modify Window "1ms" 2024/12/19 02:04:29 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-hixiwuz4newu/dst" 2024/12/19 02:04:30 DEBUG : Creating backend with remote "TestDrive:crypt/migt86lmhkdmp5mgvq09tvu1uvaavurlpu91lhqg4rsp22d6epjg/31u3jie661vd5p8j7rtc3hgbh0" 2024/12/19 02:04:31 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-hixiwuz4newu/CompareDest" 2024/12/19 02:04:31 DEBUG : Creating backend with remote "TestDrive:crypt/migt86lmhkdmp5mgvq09tvu1uvaavurlpu91lhqg4rsp22d6epjg/gveqi14airsml4bgu7krj116o8" 2024/12/19 02:04:33 DEBUG : one: Need to transfer - File not found at Destination 2024/12/19 02:04:33 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hixiwuz4newu/dst': Waiting for checks to finish 2024/12/19 02:04:33 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hixiwuz4newu/dst': Waiting for transfers to finish 2024/12/19 02:04:35 DEBUG : one: md5 = 58a885d4b7a730fa86f3e4c04ab795e4 OK 2024/12/19 02:04:35 INFO : one: Copied (new) 2024/12/19 02:04:35 DEBUG : Waiting for deletions to finish 2024/12/19 02:04:37 DEBUG : one: Sizes differ (src 5 vs dst 3) 2024/12/19 02:04:37 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hixiwuz4newu/dst': Waiting for checks to finish 2024/12/19 02:04:37 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hixiwuz4newu/dst': Waiting for transfers to finish 2024/12/19 02:04:39 DEBUG : one: md5 = 07ebffbd189de94b2e5ffea130bac33a OK 2024/12/19 02:04:39 INFO : one: Copied (replaced existing) 2024/12/19 02:04:39 DEBUG : Waiting for deletions to finish 2024/12/19 02:04:41 DEBUG : dst/one: md5 = a42df975c5021615ec537bcf0b535ae8 OK 2024/12/19 02:04:43 DEBUG : CompareDest/one: md5 = 0abee4ac05f523107ba1b522ebc60769 OK 2024/12/19 02:04:44 DEBUG : one: Sizes differ (src 5 vs dst 3) 2024/12/19 02:04:44 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hixiwuz4newu/dst': Waiting for checks to finish 2024/12/19 02:04:44 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2024/12/19 02:04:44 DEBUG : one: Destination found in --compare-dest, skipping 2024/12/19 02:04:44 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hixiwuz4newu/dst': Waiting for transfers to finish 2024/12/19 02:04:44 DEBUG : Waiting for deletions to finish 2024/12/19 02:04:44 INFO : There was nothing to transfer 2024/12/19 02:04:46 DEBUG : CompareDest/two: md5 = fdf1b674e8120c8dea9d48a396bd817a OK 2024/12/19 02:04:48 DEBUG : two: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2024/12/19 02:04:48 DEBUG : two: Destination found in --compare-dest, skipping 2024/12/19 02:04:48 DEBUG : one: Sizes differ (src 5 vs dst 3) 2024/12/19 02:04:48 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hixiwuz4newu/dst': Waiting for checks to finish 2024/12/19 02:04:48 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2024/12/19 02:04:48 DEBUG : one: Destination found in --compare-dest, skipping 2024/12/19 02:04:48 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hixiwuz4newu/dst': Waiting for transfers to finish 2024/12/19 02:04:48 DEBUG : Waiting for deletions to finish 2024/12/19 02:04:48 INFO : There was nothing to transfer 2024/12/19 02:04:49 DEBUG : two: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2024/12/19 02:04:49 DEBUG : two: Destination found in --compare-dest, skipping 2024/12/19 02:04:49 DEBUG : one: Sizes differ (src 5 vs dst 3) 2024/12/19 02:04:49 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hixiwuz4newu/dst': Waiting for checks to finish 2024/12/19 02:04:49 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2024/12/19 02:04:49 DEBUG : one: Destination found in --compare-dest, skipping 2024/12/19 02:04:49 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hixiwuz4newu/dst': Waiting for transfers to finish 2024/12/19 02:04:49 DEBUG : Waiting for deletions to finish 2024/12/19 02:04:49 INFO : There was nothing to transfer sync_test.go:2175: No hash on uploaded file so skipping compare timestamp test 2024/12/19 02:04:51 DEBUG : two: Sizes differ (src 5 vs dst 3) 2024/12/19 02:04:51 DEBUG : two: Need to transfer - File not found at Destination 2024/12/19 02:04:51 DEBUG : one: Sizes differ (src 5 vs dst 3) 2024/12/19 02:04:51 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hixiwuz4newu/dst': Waiting for checks to finish 2024/12/19 02:04:51 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2024/12/19 02:04:51 DEBUG : one: Destination found in --compare-dest, skipping 2024/12/19 02:04:51 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hixiwuz4newu/dst': Waiting for transfers to finish 2024/12/19 02:04:53 DEBUG : two: md5 = c629c8bc92db0acb4e71b641f070c419 OK 2024/12/19 02:04:53 INFO : two: Copied (new) 2024/12/19 02:04:53 DEBUG : Waiting for deletions to finish 2024/12/19 02:04:57 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k" 2024/12/19 02:04:57 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" 2024/12/19 02:04:58 DEBUG : gveqi14airsml4bgu7krj116o8: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k" 2024/12/19 02:04:58 DEBUG : gveqi14airsml4bgu7krj116o8: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" --- PASS: TestSyncCompareDest (29.70s) === RUN TestSyncMultipleCompareDest run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-hixiwuz4newu'", Local "Local file system at /tmp/rclone3755433712", Modify Window "1ms" 2024/12/19 02:05:02 DEBUG : pre-dest1/1: md5 = 66753c61fe4790bf3947446229be9e2d OK 2024/12/19 02:05:05 DEBUG : pre-dest2/2: md5 = 4b430831d87cef4e2afd2ff02cba1904 OK 2024/12/19 02:05:06 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-hixiwuz4newu/dest" 2024/12/19 02:05:06 DEBUG : Creating backend with remote "TestDrive:crypt/migt86lmhkdmp5mgvq09tvu1uvaavurlpu91lhqg4rsp22d6epjg/rg03c1jvnehrrc617i0lnqjddc" 2024/12/19 02:05:07 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-hixiwuz4newu/pre-dest1" 2024/12/19 02:05:07 DEBUG : Creating backend with remote "TestDrive:crypt/migt86lmhkdmp5mgvq09tvu1uvaavurlpu91lhqg4rsp22d6epjg/bbnblvh6k061ssopqrp18kd7gc" 2024/12/19 02:05:08 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-hixiwuz4newu/pre-dest2" 2024/12/19 02:05:08 DEBUG : Creating backend with remote "TestDrive:crypt/migt86lmhkdmp5mgvq09tvu1uvaavurlpu91lhqg4rsp22d6epjg/dgicm1h6b5ejvlltm8eeif0bnk" 2024/12/19 02:05:09 DEBUG : 1: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2024/12/19 02:05:09 DEBUG : 1: Destination found in --compare-dest, skipping 2024/12/19 02:05:10 DEBUG : 2: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2024/12/19 02:05:10 DEBUG : 2: Destination found in --compare-dest, skipping 2024/12/19 02:05:10 DEBUG : 3: Need to transfer - File not found at Destination 2024/12/19 02:05:10 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hixiwuz4newu/dest': Waiting for checks to finish 2024/12/19 02:05:10 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hixiwuz4newu/dest': Waiting for transfers to finish 2024/12/19 02:05:13 DEBUG : 3: md5 = b1931fa4263808abe7afbf1ba5dbb774 OK 2024/12/19 02:05:13 INFO : 3: Copied (new) 2024/12/19 02:05:13 DEBUG : Waiting for deletions to finish 2024/12/19 02:05:17 DEBUG : dgicm1h6b5ejvlltm8eeif0bnk: Rmdir: contains trashed file: "1ghu8geql9vrl726n32nrf65bc" 2024/12/19 02:05:17 DEBUG : bbnblvh6k061ssopqrp18kd7gc: Rmdir: contains trashed file: "skbfko3oil7es0lj68ob574sro" 2024/12/19 02:05:18 DEBUG : rg03c1jvnehrrc617i0lnqjddc: Rmdir: contains trashed file: "g072p7hmjchlnj0gibe64c1epg" --- PASS: TestSyncMultipleCompareDest (19.88s) === RUN TestSyncCopyDest run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-hixiwuz4newu'", Local "Local file system at /tmp/rclone3755433712", Modify Window "1ms" 2024/12/19 02:05:19 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-hixiwuz4newu/dst" 2024/12/19 02:05:19 DEBUG : Creating backend with remote "TestDrive:crypt/migt86lmhkdmp5mgvq09tvu1uvaavurlpu91lhqg4rsp22d6epjg/31u3jie661vd5p8j7rtc3hgbh0" 2024/12/19 02:05:21 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-hixiwuz4newu/CopyDest" 2024/12/19 02:05:21 DEBUG : Creating backend with remote "TestDrive:crypt/migt86lmhkdmp5mgvq09tvu1uvaavurlpu91lhqg4rsp22d6epjg/d09o6po3f7bm6ce32vdgs8h9ls" 2024/12/19 02:05:22 DEBUG : one: Need to transfer - File not found at Destination 2024/12/19 02:05:22 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hixiwuz4newu/dst': Waiting for checks to finish 2024/12/19 02:05:22 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hixiwuz4newu/dst': Waiting for transfers to finish 2024/12/19 02:05:25 DEBUG : one: md5 = e9792899ee5b7be66d3d204c7a4dfaa2 OK 2024/12/19 02:05:25 INFO : one: Copied (new) 2024/12/19 02:05:25 DEBUG : Waiting for deletions to finish 2024/12/19 02:05:26 DEBUG : one: Sizes differ (src 5 vs dst 3) 2024/12/19 02:05:26 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hixiwuz4newu/dst': Waiting for checks to finish 2024/12/19 02:05:26 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hixiwuz4newu/dst': Waiting for transfers to finish 2024/12/19 02:05:28 DEBUG : one: md5 = f24feb13007479b424e3d5a616e62790 OK 2024/12/19 02:05:28 INFO : one: Copied (replaced existing) 2024/12/19 02:05:28 DEBUG : Waiting for deletions to finish 2024/12/19 02:05:30 DEBUG : dst/one: md5 = 170a5f22328763873fc29c7cf50255ac OK 2024/12/19 02:05:33 DEBUG : CopyDest/one: md5 = 49597e1fbe5a0415576b5e81e5343b5f OK 2024/12/19 02:05:33 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-hixiwuz4newu/BackupDir" 2024/12/19 02:05:33 DEBUG : Creating backend with remote "TestDrive:crypt/migt86lmhkdmp5mgvq09tvu1uvaavurlpu91lhqg4rsp22d6epjg/s6dbk3lfi7c9kfvo6j7bla9m0g" 2024/12/19 02:05:35 DEBUG : one: Sizes differ (src 5 vs dst 3) 2024/12/19 02:05:35 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hixiwuz4newu/dst': Waiting for checks to finish 2024/12/19 02:05:35 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2024/12/19 02:05:35 DEBUG : one: Sizes differ (src 5 vs dst 3) 2024/12/19 02:05:37 INFO : one: Moved (server-side) 2024/12/19 02:05:39 INFO : one: Copied (server-side copy) 2024/12/19 02:05:39 DEBUG : one: Destination found in --copy-dest, using server-side copy 2024/12/19 02:05:39 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hixiwuz4newu/dst': Waiting for transfers to finish 2024/12/19 02:05:39 DEBUG : Waiting for deletions to finish 2024/12/19 02:05:41 DEBUG : CopyDest/two: md5 = ce09d43f382894b6ff2d3d251f2ed7da OK 2024/12/19 02:05:42 DEBUG : two: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2024/12/19 02:05:43 INFO : two: Copied (server-side copy) 2024/12/19 02:05:43 DEBUG : two: Destination found in --copy-dest, using server-side copy 2024/12/19 02:05:43 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2024/12/19 02:05:43 DEBUG : one: Unchanged skipping 2024/12/19 02:05:43 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hixiwuz4newu/dst': Waiting for checks to finish 2024/12/19 02:05:43 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hixiwuz4newu/dst': Waiting for transfers to finish 2024/12/19 02:05:43 DEBUG : Waiting for deletions to finish 2024/12/19 02:05:44 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2024/12/19 02:05:44 DEBUG : one: Unchanged skipping 2024/12/19 02:05:44 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hixiwuz4newu/dst': Waiting for checks to finish 2024/12/19 02:05:44 DEBUG : two: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2024/12/19 02:05:44 DEBUG : two: Unchanged skipping 2024/12/19 02:05:44 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hixiwuz4newu/dst': Waiting for transfers to finish 2024/12/19 02:05:44 DEBUG : Waiting for deletions to finish 2024/12/19 02:05:44 INFO : There was nothing to transfer 2024/12/19 02:05:46 DEBUG : CopyDest/three: md5 = 7c99588c3c619b432de64dcf45df9893 OK 2024/12/19 02:05:47 DEBUG : three: Sizes differ (src 7 vs dst 5) 2024/12/19 02:05:47 DEBUG : three: Destination not found in --copy-dest 2024/12/19 02:05:47 DEBUG : three: Need to transfer - File not found at Destination 2024/12/19 02:05:47 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2024/12/19 02:05:47 DEBUG : one: Unchanged skipping 2024/12/19 02:05:47 DEBUG : two: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2024/12/19 02:05:47 DEBUG : two: Unchanged skipping 2024/12/19 02:05:47 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hixiwuz4newu/dst': Waiting for checks to finish 2024/12/19 02:05:47 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hixiwuz4newu/dst': Waiting for transfers to finish 2024/12/19 02:05:49 DEBUG : three: md5 = bd15b0e09fcfd6403ec7b777c90ecda9 OK 2024/12/19 02:05:49 INFO : three: Copied (new) 2024/12/19 02:05:49 DEBUG : Waiting for deletions to finish 2024/12/19 02:05:54 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "b6jdmn2b1adrhc8vikh7edr9os" 2024/12/19 02:05:54 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" 2024/12/19 02:05:54 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k" 2024/12/19 02:05:55 DEBUG : d09o6po3f7bm6ce32vdgs8h9ls: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k" 2024/12/19 02:05:55 DEBUG : d09o6po3f7bm6ce32vdgs8h9ls: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" 2024/12/19 02:05:55 DEBUG : d09o6po3f7bm6ce32vdgs8h9ls: Rmdir: contains trashed file: "b6jdmn2b1adrhc8vikh7edr9os" 2024/12/19 02:05:55 DEBUG : s6dbk3lfi7c9kfvo6j7bla9m0g: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" --- PASS: TestSyncCopyDest (37.34s) === RUN TestSyncBackupDir run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-hixiwuz4newu'", Local "Local file system at /tmp/rclone3755433712", Modify Window "1ms" 2024/12/19 02:05:59 DEBUG : dst/one: md5 = 50ebd73470fb0b86be88b63cfed242a6 OK 2024/12/19 02:06:01 DEBUG : dst/two: md5 = 043e321e7a957b839d4c217291de2de9 OK 2024/12/19 02:06:03 DEBUG : dst/three.txt: md5 = 6134e6cfe57a5185f81ea5a4de250afc OK 2024/12/19 02:06:03 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-hixiwuz4newu/dst" 2024/12/19 02:06:03 DEBUG : Creating backend with remote "TestDrive:crypt/migt86lmhkdmp5mgvq09tvu1uvaavurlpu91lhqg4rsp22d6epjg/31u3jie661vd5p8j7rtc3hgbh0" 2024/12/19 02:06:04 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-hixiwuz4newu/backup" 2024/12/19 02:06:04 DEBUG : Creating backend with remote "TestDrive:crypt/migt86lmhkdmp5mgvq09tvu1uvaavurlpu91lhqg4rsp22d6epjg/1nrff024r7pq65ecp72fc28jb0" 2024/12/19 02:06:06 DEBUG : one: Sizes differ (src 4 vs dst 3) 2024/12/19 02:06:06 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2024/12/19 02:06:06 DEBUG : two: Unchanged skipping 2024/12/19 02:06:06 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hixiwuz4newu/dst': Waiting for checks to finish 2024/12/19 02:06:08 INFO : one: Moved (server-side) 2024/12/19 02:06:08 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hixiwuz4newu/dst': Waiting for transfers to finish 2024/12/19 02:06:09 DEBUG : one: md5 = b41077d6b018dc996dcafd7ad4adbc87 OK 2024/12/19 02:06:09 INFO : one: Copied (new) 2024/12/19 02:06:09 DEBUG : Waiting for deletions to finish 2024/12/19 02:06:11 INFO : three.txt: Moved (server-side) 2024/12/19 02:06:11 INFO : three.txt: Moved into backup dir 2024/12/19 02:06:13 DEBUG : dst/three.txt: md5 = f9626940ae6a21819a0299b46cb62582 OK 2024/12/19 02:06:13 DEBUG : one: Sizes differ (src 5 vs dst 4) 2024/12/19 02:06:13 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2024/12/19 02:06:13 DEBUG : two: Unchanged skipping 2024/12/19 02:06:13 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hixiwuz4newu/dst': Waiting for checks to finish 2024/12/19 02:06:14 INFO : one: Deleted 2024/12/19 02:06:15 INFO : one: Moved (server-side) 2024/12/19 02:06:15 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hixiwuz4newu/dst': Waiting for transfers to finish 2024/12/19 02:06:17 DEBUG : one: md5 = c83af30faa83decbd7edfe87f83826eb OK 2024/12/19 02:06:17 INFO : one: Copied (new) 2024/12/19 02:06:17 DEBUG : Waiting for deletions to finish 2024/12/19 02:06:18 INFO : three.txt: Deleted 2024/12/19 02:06:19 INFO : three.txt: Moved (server-side) 2024/12/19 02:06:19 INFO : three.txt: Moved into backup dir 2024/12/19 02:06:22 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" 2024/12/19 02:06:22 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k" 2024/12/19 02:06:23 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" 2024/12/19 02:06:23 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "tr2hj63d80ftlmvm6a952snjcc" 2024/12/19 02:06:23 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" 2024/12/19 02:06:23 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "tr2hj63d80ftlmvm6a952snjcc" --- PASS: TestSyncBackupDir (27.49s) === RUN TestSyncBackupDirWithSuffix run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-hixiwuz4newu'", Local "Local file system at /tmp/rclone3755433712", Modify Window "1ms" 2024/12/19 02:06:27 DEBUG : dst/one: md5 = 4e2e8edc7585262dd15daaa67a6115d4 OK 2024/12/19 02:06:28 DEBUG : dst/two: md5 = 7b88a8c12da795ead81a2856fdf5b7ab OK 2024/12/19 02:06:30 DEBUG : dst/three.txt: md5 = 8155fac50fe416cb10c88931f98da374 OK 2024/12/19 02:06:31 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-hixiwuz4newu/dst" 2024/12/19 02:06:31 DEBUG : Creating backend with remote "TestDrive:crypt/migt86lmhkdmp5mgvq09tvu1uvaavurlpu91lhqg4rsp22d6epjg/31u3jie661vd5p8j7rtc3hgbh0" 2024/12/19 02:06:31 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-hixiwuz4newu/backup" 2024/12/19 02:06:31 DEBUG : Creating backend with remote "TestDrive:crypt/migt86lmhkdmp5mgvq09tvu1uvaavurlpu91lhqg4rsp22d6epjg/1nrff024r7pq65ecp72fc28jb0" 2024/12/19 02:06:33 DEBUG : one: Sizes differ (src 4 vs dst 3) 2024/12/19 02:06:33 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2024/12/19 02:06:33 DEBUG : two: Unchanged skipping 2024/12/19 02:06:33 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hixiwuz4newu/dst': Waiting for checks to finish 2024/12/19 02:06:35 INFO : one: Moved (server-side) to: one.bak 2024/12/19 02:06:35 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hixiwuz4newu/dst': Waiting for transfers to finish 2024/12/19 02:06:37 DEBUG : one: md5 = a6c25cd1472698658390e6d561afb0c7 OK 2024/12/19 02:06:37 INFO : one: Copied (new) 2024/12/19 02:06:37 DEBUG : Waiting for deletions to finish 2024/12/19 02:06:38 INFO : three.txt: Moved (server-side) to: three.txt.bak 2024/12/19 02:06:38 INFO : three.txt: Moved into backup dir 2024/12/19 02:06:40 DEBUG : dst/three.txt: md5 = 5c5f91394f22c979d37b91bb3e3432e8 OK 2024/12/19 02:06:41 DEBUG : one: Sizes differ (src 5 vs dst 4) 2024/12/19 02:06:41 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hixiwuz4newu/dst': Waiting for checks to finish 2024/12/19 02:06:41 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2024/12/19 02:06:41 DEBUG : two: Unchanged skipping 2024/12/19 02:06:42 INFO : one.bak: Deleted 2024/12/19 02:06:43 INFO : one: Moved (server-side) to: one.bak 2024/12/19 02:06:43 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hixiwuz4newu/dst': Waiting for transfers to finish 2024/12/19 02:06:45 DEBUG : one: md5 = 3a88ad91ef2f5c9192738eb977bb8e16 OK 2024/12/19 02:06:45 INFO : one: Copied (new) 2024/12/19 02:06:45 DEBUG : Waiting for deletions to finish 2024/12/19 02:06:46 INFO : three.txt.bak: Deleted 2024/12/19 02:06:46 INFO : three.txt: Moved (server-side) to: three.txt.bak 2024/12/19 02:06:46 INFO : three.txt: Moved into backup dir 2024/12/19 02:06:50 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" 2024/12/19 02:06:50 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k" 2024/12/19 02:06:51 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "sk91qgsqfn0r271r2ehsaoc20c" 2024/12/19 02:06:51 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "qltcak2uaegtmcoa8vijdppbp8" 2024/12/19 02:06:51 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "qltcak2uaegtmcoa8vijdppbp8" 2024/12/19 02:06:51 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "sk91qgsqfn0r271r2ehsaoc20c" --- PASS: TestSyncBackupDirWithSuffix (27.68s) === RUN TestSyncBackupDirWithSuffixKeepExtension run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-hixiwuz4newu'", Local "Local file system at /tmp/rclone3755433712", Modify Window "1ms" 2024/12/19 02:06:54 DEBUG : dst/one: md5 = c0a434f40ab9a1c1a30adfa18ae5e285 OK 2024/12/19 02:06:56 DEBUG : dst/two: md5 = e843f1dfe6fb598b9114d9d32a5e0596 OK 2024/12/19 02:06:58 DEBUG : dst/three.txt: md5 = 4bba068cfb3969f25e5b7fab7e7227a9 OK 2024/12/19 02:06:59 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-hixiwuz4newu/dst" 2024/12/19 02:06:59 DEBUG : Creating backend with remote "TestDrive:crypt/migt86lmhkdmp5mgvq09tvu1uvaavurlpu91lhqg4rsp22d6epjg/31u3jie661vd5p8j7rtc3hgbh0" 2024/12/19 02:06:59 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-hixiwuz4newu/backup" 2024/12/19 02:06:59 DEBUG : Creating backend with remote "TestDrive:crypt/migt86lmhkdmp5mgvq09tvu1uvaavurlpu91lhqg4rsp22d6epjg/1nrff024r7pq65ecp72fc28jb0" 2024/12/19 02:07:01 DEBUG : one: Sizes differ (src 4 vs dst 3) 2024/12/19 02:07:01 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2024/12/19 02:07:01 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hixiwuz4newu/dst': Waiting for checks to finish 2024/12/19 02:07:01 DEBUG : two: Unchanged skipping 2024/12/19 02:07:03 INFO : one: Moved (server-side) to: one-2019-01-01 2024/12/19 02:07:03 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hixiwuz4newu/dst': Waiting for transfers to finish 2024/12/19 02:07:05 DEBUG : one: md5 = 0a98044e729a7ab6fe24b52b188d004e OK 2024/12/19 02:07:05 INFO : one: Copied (new) 2024/12/19 02:07:05 DEBUG : Waiting for deletions to finish 2024/12/19 02:07:06 INFO : three.txt: Moved (server-side) to: three-2019-01-01.txt 2024/12/19 02:07:06 INFO : three.txt: Moved into backup dir 2024/12/19 02:07:08 DEBUG : dst/three.txt: md5 = a6bc8cf86c93a69cbc2843d6aa2598b8 OK 2024/12/19 02:07:10 DEBUG : one: Sizes differ (src 5 vs dst 4) 2024/12/19 02:07:10 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2024/12/19 02:07:10 DEBUG : two: Unchanged skipping 2024/12/19 02:07:10 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hixiwuz4newu/dst': Waiting for checks to finish 2024/12/19 02:07:10 INFO : one-2019-01-01: Deleted 2024/12/19 02:07:11 INFO : one: Moved (server-side) to: one-2019-01-01 2024/12/19 02:07:11 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hixiwuz4newu/dst': Waiting for transfers to finish 2024/12/19 02:07:13 DEBUG : one: md5 = cd0c25bfe27ff6b31e34955119da241e OK 2024/12/19 02:07:13 INFO : one: Copied (new) 2024/12/19 02:07:13 DEBUG : Waiting for deletions to finish 2024/12/19 02:07:14 INFO : three-2019-01-01.txt: Deleted 2024/12/19 02:07:15 INFO : three.txt: Moved (server-side) to: three-2019-01-01.txt 2024/12/19 02:07:15 INFO : three.txt: Moved into backup dir 2024/12/19 02:07:18 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" 2024/12/19 02:07:18 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k" 2024/12/19 02:07:19 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "qtq2f6qq4lgpsmj88vb7147qje3prudmtfdtr2342fth58vo9a50" 2024/12/19 02:07:19 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "jcjl1bv3ep0v8kt35lqql1co90" 2024/12/19 02:07:19 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "qtq2f6qq4lgpsmj88vb7147qje3prudmtfdtr2342fth58vo9a50" 2024/12/19 02:07:19 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "jcjl1bv3ep0v8kt35lqql1co90" --- PASS: TestSyncBackupDirWithSuffixKeepExtension (28.32s) === RUN TestSyncBackupDirSuffixOnly run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-hixiwuz4newu'", Local "Local file system at /tmp/rclone3755433712", Modify Window "1ms" 2024/12/19 02:07:23 DEBUG : dst/one: md5 = bf46abf0c195729dd34a93f34326da02 OK 2024/12/19 02:07:24 DEBUG : dst/two: md5 = 2aeb6bf469e375ad68bd7d1e08eb3cee OK 2024/12/19 02:07:26 DEBUG : dst/three.txt: md5 = 1f8bf15fc692647eeb9319cf2a95e553 OK 2024/12/19 02:07:27 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-hixiwuz4newu/dst" 2024/12/19 02:07:27 DEBUG : Creating backend with remote "TestDrive:crypt/migt86lmhkdmp5mgvq09tvu1uvaavurlpu91lhqg4rsp22d6epjg/31u3jie661vd5p8j7rtc3hgbh0" 2024/12/19 02:07:28 DEBUG : one: Sizes differ (src 4 vs dst 3) 2024/12/19 02:07:28 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2024/12/19 02:07:28 DEBUG : two: Unchanged skipping 2024/12/19 02:07:28 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hixiwuz4newu/dst': Waiting for checks to finish 2024/12/19 02:07:28 INFO : one: Moved (server-side) to: one.bak 2024/12/19 02:07:28 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hixiwuz4newu/dst': Waiting for transfers to finish 2024/12/19 02:07:30 DEBUG : one: md5 = 6d9aa164b700b376764a202bd8cf3d8d OK 2024/12/19 02:07:30 INFO : one: Copied (new) 2024/12/19 02:07:30 DEBUG : Waiting for deletions to finish 2024/12/19 02:07:31 INFO : three.txt: Moved (server-side) to: three.txt.bak 2024/12/19 02:07:31 INFO : three.txt: Moved into backup dir 2024/12/19 02:07:33 DEBUG : dst/three.txt: md5 = 83e6864a2f4589ea72a2678271d415f2 OK 2024/12/19 02:07:34 DEBUG : three.txt.bak: Excluded (Path Filter) 2024/12/19 02:07:34 DEBUG : three.txt.bak: Excluded 2024/12/19 02:07:34 DEBUG : one.bak: Excluded (Path Filter) 2024/12/19 02:07:34 DEBUG : one.bak: Excluded 2024/12/19 02:07:34 DEBUG : one: Sizes differ (src 5 vs dst 4) 2024/12/19 02:07:34 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2024/12/19 02:07:34 DEBUG : two: Unchanged skipping 2024/12/19 02:07:34 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hixiwuz4newu/dst': Waiting for checks to finish 2024/12/19 02:07:35 INFO : one.bak: Deleted 2024/12/19 02:07:36 INFO : one: Moved (server-side) to: one.bak 2024/12/19 02:07:36 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hixiwuz4newu/dst': Waiting for transfers to finish 2024/12/19 02:07:37 DEBUG : one: md5 = c4e34229c00d3064c4786a510f0a8e41 OK 2024/12/19 02:07:37 INFO : one: Copied (new) 2024/12/19 02:07:37 DEBUG : Waiting for deletions to finish 2024/12/19 02:07:38 INFO : three.txt.bak: Deleted 2024/12/19 02:07:39 INFO : three.txt: Moved (server-side) to: three.txt.bak 2024/12/19 02:07:39 INFO : three.txt: Moved into backup dir 2024/12/19 02:07:42 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" 2024/12/19 02:07:42 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "qltcak2uaegtmcoa8vijdppbp8" 2024/12/19 02:07:42 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "sk91qgsqfn0r271r2ehsaoc20c" 2024/12/19 02:07:42 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "sk91qgsqfn0r271r2ehsaoc20c" 2024/12/19 02:07:42 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "qltcak2uaegtmcoa8vijdppbp8" 2024/12/19 02:07:42 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k" --- PASS: TestSyncBackupDirSuffixOnly (23.18s) === RUN TestSyncSuffix run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-hixiwuz4newu'", Local "Local file system at /tmp/rclone3755433712", Modify Window "1ms" 2024/12/19 02:07:46 DEBUG : dst/one: md5 = 3e17549d058bc2203c0e42626bea65e5 OK 2024/12/19 02:07:47 DEBUG : dst/two: md5 = e8e527d0a6cea6ff53ddc6359de5daa0 OK 2024/12/19 02:07:49 DEBUG : dst/three.txt: md5 = 2ccfd6e1fcb7d2cfc8bf41c9aefd549d OK 2024/12/19 02:07:49 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-hixiwuz4newu/dst" 2024/12/19 02:07:49 DEBUG : Creating backend with remote "TestDrive:crypt/migt86lmhkdmp5mgvq09tvu1uvaavurlpu91lhqg4rsp22d6epjg/31u3jie661vd5p8j7rtc3hgbh0" 2024/12/19 02:07:50 DEBUG : one: Sizes differ (src 4 vs dst 3) 2024/12/19 02:07:51 INFO : one: Moved (server-side) to: one.bak 2024/12/19 02:07:53 DEBUG : one: md5 = 461944a9d2c886e88f9c302290104609 OK 2024/12/19 02:07:53 INFO : one: Copied (new) 2024/12/19 02:07:53 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2024/12/19 02:07:53 DEBUG : two: Unchanged skipping 2024/12/19 02:07:53 DEBUG : three.txt: Sizes differ (src 6 vs dst 5) 2024/12/19 02:07:54 INFO : three.txt: Moved (server-side) to: three.txt.bak 2024/12/19 02:07:56 DEBUG : three.txt: md5 = a2cd46b57e8c0645e5b1d32d6aa01786 OK 2024/12/19 02:07:56 INFO : three.txt: Copied (new) 2024/12/19 02:07:57 DEBUG : one: Sizes differ (src 5 vs dst 4) 2024/12/19 02:07:58 INFO : one.bak: Deleted 2024/12/19 02:07:59 INFO : one: Moved (server-side) to: one.bak 2024/12/19 02:08:01 DEBUG : one: md5 = d4546c4a6808c93a45a38bcf9492c897 OK 2024/12/19 02:08:01 INFO : one: Copied (new) 2024/12/19 02:08:01 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2024/12/19 02:08:01 DEBUG : two: Unchanged skipping 2024/12/19 02:08:01 DEBUG : three.txt: Sizes differ (src 19 vs dst 6) 2024/12/19 02:08:02 INFO : three.txt.bak: Deleted 2024/12/19 02:08:02 INFO : three.txt: Moved (server-side) to: three.txt.bak 2024/12/19 02:08:04 DEBUG : three.txt: md5 = 43a5c75c26b06e0218dc455b63e7e406 OK 2024/12/19 02:08:04 INFO : three.txt: Copied (new) 2024/12/19 02:08:10 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "tr2hj63d80ftlmvm6a952snjcc" 2024/12/19 02:08:10 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" 2024/12/19 02:08:10 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "qltcak2uaegtmcoa8vijdppbp8" 2024/12/19 02:08:10 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "sk91qgsqfn0r271r2ehsaoc20c" 2024/12/19 02:08:10 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k" 2024/12/19 02:08:10 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "qltcak2uaegtmcoa8vijdppbp8" 2024/12/19 02:08:10 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "sk91qgsqfn0r271r2ehsaoc20c" --- PASS: TestSyncSuffix (27.48s) === RUN TestSyncSuffixKeepExtension run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-hixiwuz4newu'", Local "Local file system at /tmp/rclone3755433712", Modify Window "1ms" 2024/12/19 02:08:13 DEBUG : dst/one: md5 = b3d140590dc60bcdaf9e2159670304f3 OK 2024/12/19 02:08:15 DEBUG : dst/two: md5 = 3d6f2ca7573691b2f877ff6e86f909c9 OK 2024/12/19 02:08:17 DEBUG : dst/three.txt: md5 = 457d2032866ced8d49286a82766f3fd8 OK 2024/12/19 02:08:17 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-hixiwuz4newu/dst" 2024/12/19 02:08:17 DEBUG : Creating backend with remote "TestDrive:crypt/migt86lmhkdmp5mgvq09tvu1uvaavurlpu91lhqg4rsp22d6epjg/31u3jie661vd5p8j7rtc3hgbh0" 2024/12/19 02:08:18 DEBUG : one: Sizes differ (src 4 vs dst 3) 2024/12/19 02:08:19 INFO : one: Moved (server-side) to: one-2019-01-01 2024/12/19 02:08:21 DEBUG : one: md5 = 8701eab24b9f5da8e12606ab9e59a59f OK 2024/12/19 02:08:21 INFO : one: Copied (new) 2024/12/19 02:08:21 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2024/12/19 02:08:21 DEBUG : two: Unchanged skipping 2024/12/19 02:08:22 DEBUG : three.txt: Sizes differ (src 6 vs dst 5) 2024/12/19 02:08:22 INFO : three.txt: Moved (server-side) to: three-2019-01-01.txt 2024/12/19 02:08:24 DEBUG : three.txt: md5 = 54ee34f6efbdd2a219e28dc476863bb9 OK 2024/12/19 02:08:24 INFO : three.txt: Copied (new) 2024/12/19 02:08:25 DEBUG : one: Sizes differ (src 5 vs dst 4) 2024/12/19 02:08:26 INFO : one-2019-01-01: Deleted 2024/12/19 02:08:27 INFO : one: Moved (server-side) to: one-2019-01-01 2024/12/19 02:08:28 DEBUG : one: md5 = 6768466a6dcecf1963d83481a5d49b58 OK 2024/12/19 02:08:28 INFO : one: Copied (new) 2024/12/19 02:08:29 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2024/12/19 02:08:29 DEBUG : two: Unchanged skipping 2024/12/19 02:08:29 DEBUG : three.txt: Sizes differ (src 19 vs dst 6) 2024/12/19 02:08:30 INFO : three-2019-01-01.txt: Deleted 2024/12/19 02:08:30 INFO : three.txt: Moved (server-side) to: three-2019-01-01.txt 2024/12/19 02:08:32 DEBUG : three.txt: md5 = 81ac904cf242413b1c015e341761a5d7 OK 2024/12/19 02:08:32 INFO : three.txt: Copied (new) 2024/12/19 02:08:36 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "tr2hj63d80ftlmvm6a952snjcc" 2024/12/19 02:08:36 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" 2024/12/19 02:08:36 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "jcjl1bv3ep0v8kt35lqql1co90" 2024/12/19 02:08:36 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k" 2024/12/19 02:08:36 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "jcjl1bv3ep0v8kt35lqql1co90" 2024/12/19 02:08:36 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "qtq2f6qq4lgpsmj88vb7147qje3prudmtfdtr2342fth58vo9a50" 2024/12/19 02:08:36 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "qtq2f6qq4lgpsmj88vb7147qje3prudmtfdtr2342fth58vo9a50" --- PASS: TestSyncSuffixKeepExtension (26.13s) === RUN TestSyncUTFNorm run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-hixiwuz4newu'", Local "Local file system at /tmp/rclone3755433712", Modify Window "1ms" 2024/12/19 02:08:38 DEBUG : Testêé: md5 = d634df57cb3620137319244759bba790 OK 2024/12/19 02:08:39 DEBUG : Testêé: Sizes differ (src 14 vs dst 18) 2024/12/19 02:08:39 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hixiwuz4newu': Waiting for checks to finish 2024/12/19 02:08:39 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hixiwuz4newu': Waiting for transfers to finish 2024/12/19 02:08:40 DEBUG : Testêé: md5 = 1e4ee48ec794a74d4b90e2b1c4586bd6 OK 2024/12/19 02:08:40 INFO : Testêé: Copied (replaced existing) to: Testêé 2024/12/19 02:08:40 DEBUG : Waiting for deletions to finish --- PASS: TestSyncUTFNorm (4.68s) === RUN TestSyncImmutable run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-hixiwuz4newu'", Local "Local file system at /tmp/rclone3755433712", Modify Window "1ms" 2024/12/19 02:08:42 DEBUG : existing: Need to transfer - File not found at Destination 2024/12/19 02:08:42 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hixiwuz4newu': Waiting for checks to finish 2024/12/19 02:08:42 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hixiwuz4newu': Waiting for transfers to finish 2024/12/19 02:08:44 DEBUG : existing: md5 = eca79737927eb9f548f3bab1f7da7537 OK 2024/12/19 02:08:44 INFO : existing: Copied (new) 2024/12/19 02:08:44 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-hixiwuz4newu'", Local "Local file system at /tmp/rclone3755433712", Modify Window "1ms" 2024/12/19 02:08:44 DEBUG : existing: Sizes differ (src 8 vs dst 6) 2024/12/19 02:08:44 ERROR : existing: Source and destination exist but do not match: immutable file modified 2024/12/19 02:08:44 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hixiwuz4newu': Waiting for checks to finish 2024/12/19 02:08:44 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hixiwuz4newu': Waiting for transfers to finish 2024/12/19 02:08:44 ERROR : Encrypted drive 'TestCryptDrive:rclone-test-hixiwuz4newu': not deleting files as there were IO errors 2024/12/19 02:08:44 ERROR : Encrypted drive 'TestCryptDrive:rclone-test-hixiwuz4newu': not deleting directories as there were IO errors run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-hixiwuz4newu'", Local "Local file system at /tmp/rclone3755433712", Modify Window "1ms" --- PASS: TestSyncImmutable (5.07s) === RUN TestSyncIgnoreCase run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-hixiwuz4newu'", Local "Local file system at /tmp/rclone3755433712", Modify Window "1ms" 2024/12/19 02:08:48 DEBUG : EXISTING: md5 = 0fd7ed73700ceae4eeac44778c188a51 OK 2024/12/19 02:08:48 DEBUG : existing: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2024/12/19 02:08:48 DEBUG : existing: Unchanged skipping 2024/12/19 02:08:48 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hixiwuz4newu': Waiting for checks to finish 2024/12/19 02:08:48 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hixiwuz4newu': Waiting for transfers to finish 2024/12/19 02:08:48 DEBUG : Waiting for deletions to finish 2024/12/19 02:08:48 INFO : There was nothing to transfer --- PASS: TestSyncIgnoreCase (3.25s) === RUN TestFixCase run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-hixiwuz4newu'", Local "Local file system at /tmp/rclone3755433712", Modify Window "1ms" sync_test.go:2635: Skipping test as local or remote are case-sensitive --- SKIP: TestFixCase (0.43s) === RUN TestMaxTransfer === RUN TestMaxTransfer/Hard run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-hixiwuz4newu'", Local "Local file system at /tmp/rclone3755433712", 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-hixiwuz4newu'", Local "Local file system at /tmp/rclone3755433712", 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-hixiwuz4newu'", Local "Local file system at /tmp/rclone3755433712", Modify Window "1ms" sync_test.go:2674: This test only runs on local --- PASS: TestMaxTransfer (1.32s) --- SKIP: TestMaxTransfer/Hard (0.44s) --- SKIP: TestMaxTransfer/Soft (0.45s) --- SKIP: TestMaxTransfer/Cautious (0.43s) === RUN TestSyncConcurrentDelete run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-hixiwuz4newu'", Local "Local file system at /tmp/rclone3755433712", Modify Window "1ms" 2024/12/19 02:08:53 DEBUG : both0: md5 = a66c93a087c2fef1689a96044cab2df1 OK 2024/12/19 02:08:55 DEBUG : only0: md5 = 220e0b85f2f9b0f58c786673e008895c OK 2024/12/19 02:08:56 DEBUG : both1: md5 = 2a8d8b329fa5f787c9ef92810be21dff OK 2024/12/19 02:08:58 DEBUG : only1: md5 = ebc11aa4e040c8c5ad0bc80cea9a98f4 OK 2024/12/19 02:09:00 DEBUG : both2: md5 = 2865a47c7074093ea530b2649f9b838e OK 2024/12/19 02:09:01 DEBUG : only2: md5 = ad57b91d85811f19a1c9b3b174675f05 OK 2024/12/19 02:09:03 DEBUG : both3: md5 = fe7604794d9b19eb06f97e38d99925cd OK 2024/12/19 02:09:05 DEBUG : only3: md5 = ec91c61a9cb5b2b9cc71b436ef887d71 OK 2024/12/19 02:09:06 DEBUG : both4: md5 = 333a46d157239f4ad9c611a837d26dcd OK 2024/12/19 02:09:08 DEBUG : only4: md5 = 3191a04f977e37835665272d0fb33ab1 OK 2024/12/19 02:09:10 DEBUG : both5: md5 = ecdcf36b11bc5aa097ab115ab54fd626 OK 2024/12/19 02:09:12 DEBUG : only5: md5 = 8a194543fbc6bc6de4aac7b65cc3c6dd OK 2024/12/19 02:09:13 DEBUG : both6: md5 = 920b789f3df2bca6e3634fa596af4f65 OK 2024/12/19 02:09:15 DEBUG : only6: md5 = 02a4486191dfbeca4d3aae559297bee8 OK 2024/12/19 02:09:17 DEBUG : both7: md5 = 0c638ce0b99e6aa506b4f852a74c6d45 OK 2024/12/19 02:09:18 DEBUG : only7: md5 = ce8cf5d9d930f436a402e38386d02fd3 OK 2024/12/19 02:09:20 DEBUG : both8: md5 = f40ffd7a1191f7a031f53568eba5b03c OK 2024/12/19 02:09:22 DEBUG : only8: md5 = 2b22e553c22a31d099c81ae8935ac630 OK 2024/12/19 02:09:23 DEBUG : both9: md5 = 9d100a672862a5f82b01d14865397067 OK 2024/12/19 02:09:25 DEBUG : only9: md5 = 18ece94553d410268ad99e21fcd13cf8 OK 2024/12/19 02:09:27 DEBUG : both10: md5 = 57cda3b17e3d1eebfb7a909f0d2f8e7b OK 2024/12/19 02:09:28 DEBUG : only10: md5 = 3277bcdd901e0ca327b96644cf513765 OK 2024/12/19 02:09:30 DEBUG : both11: md5 = 8fb1206a5f8e8c25a6e8bf818a15ca3d OK 2024/12/19 02:09:31 DEBUG : only11: md5 = e7033eedca371c67e2f966403eda47f7 OK 2024/12/19 02:09:33 DEBUG : both12: md5 = 530bb41a532baefdff4664d62ed7ef20 OK 2024/12/19 02:09:35 DEBUG : only12: md5 = 0b2c9e5186cd2a56c2850dac79d841a5 OK 2024/12/19 02:09:36 DEBUG : both13: md5 = c9d61485157b9ae810a4e035497b6dfc OK 2024/12/19 02:09:38 DEBUG : only13: md5 = e0a0af5e5b5a71ca8e22b37992555985 OK 2024/12/19 02:09:40 DEBUG : both14: md5 = 4c3acf0bfc55f74dd5e14a6087a6b1b6 OK 2024/12/19 02:09:42 DEBUG : only14: md5 = 7abf8f73814ad67781842c408336a34b OK 2024/12/19 02:09:43 DEBUG : both15: md5 = b92d7423215deaf622aa5275903ce746 OK 2024/12/19 02:09:45 DEBUG : only15: md5 = ba37d2cf37e955f3efb9a730c16ed335 OK 2024/12/19 02:09:46 DEBUG : both16: md5 = f8d72df56d5558ac2e29ec56ec6b45f2 OK 2024/12/19 02:09:48 DEBUG : only16: md5 = 07389baa3a2189a0f7cac918cd7e2c48 OK 2024/12/19 02:09:50 DEBUG : both17: md5 = ff490521e215299b35b78700b0528892 OK 2024/12/19 02:09:51 DEBUG : only17: md5 = 5f9cc15d7c145d644f369a93a6a90bef OK 2024/12/19 02:09:53 DEBUG : both18: md5 = 913860f88351069af5582077e17ce4c4 OK 2024/12/19 02:09:55 DEBUG : only18: md5 = 9d238250e3d38a003515f871383aa0ef OK 2024/12/19 02:09:56 DEBUG : both19: md5 = 59cf942f7e1de1f9f3d5464dff780d5e OK 2024/12/19 02:09:58 DEBUG : only19: md5 = b97c0980a68a00463684b1501191e555 OK 2024/12/19 02:09:59 DEBUG : both0: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2024/12/19 02:09:59 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hixiwuz4newu': Waiting for checks to finish 2024/12/19 02:09:59 DEBUG : both1: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2024/12/19 02:09:59 DEBUG : both11: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2024/12/19 02:09:59 DEBUG : both10: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2024/12/19 02:09:59 DEBUG : both0: Unchanged skipping 2024/12/19 02:09:59 DEBUG : both12: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2024/12/19 02:09:59 DEBUG : both1: Unchanged skipping 2024/12/19 02:09:59 DEBUG : both13: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2024/12/19 02:09:59 DEBUG : both13: Unchanged skipping 2024/12/19 02:09:59 DEBUG : both14: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2024/12/19 02:09:59 DEBUG : both14: Unchanged skipping 2024/12/19 02:09:59 DEBUG : both15: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2024/12/19 02:09:59 DEBUG : both11: Unchanged skipping 2024/12/19 02:09:59 DEBUG : both16: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2024/12/19 02:09:59 DEBUG : both16: Unchanged skipping 2024/12/19 02:09:59 DEBUG : both17: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2024/12/19 02:09:59 DEBUG : both17: Unchanged skipping 2024/12/19 02:09:59 DEBUG : both18: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2024/12/19 02:09:59 DEBUG : both18: Unchanged skipping 2024/12/19 02:09:59 DEBUG : both19: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2024/12/19 02:09:59 DEBUG : both19: Unchanged skipping 2024/12/19 02:09:59 DEBUG : both2: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2024/12/19 02:09:59 DEBUG : both2: Unchanged skipping 2024/12/19 02:09:59 DEBUG : both3: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2024/12/19 02:09:59 DEBUG : both3: Unchanged skipping 2024/12/19 02:09:59 DEBUG : both4: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2024/12/19 02:09:59 DEBUG : both4: Unchanged skipping 2024/12/19 02:09:59 DEBUG : both5: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2024/12/19 02:09:59 DEBUG : both5: Unchanged skipping 2024/12/19 02:09:59 DEBUG : both6: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2024/12/19 02:09:59 DEBUG : both6: Unchanged skipping 2024/12/19 02:09:59 DEBUG : both7: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2024/12/19 02:09:59 DEBUG : both7: Unchanged skipping 2024/12/19 02:09:59 DEBUG : both8: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2024/12/19 02:09:59 DEBUG : both8: Unchanged skipping 2024/12/19 02:09:59 DEBUG : both9: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2024/12/19 02:09:59 DEBUG : both9: Unchanged skipping 2024/12/19 02:09:59 DEBUG : both10: Unchanged skipping 2024/12/19 02:09:59 DEBUG : both12: Unchanged skipping 2024/12/19 02:09:59 DEBUG : both15: Unchanged skipping 2024/12/19 02:09:59 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hixiwuz4newu': Waiting for transfers to finish 2024/12/19 02:09:59 DEBUG : Waiting for deletions to finish 2024/12/19 02:09:59 INFO : only11: Deleted 2024/12/19 02:09:59 INFO : only16: Deleted 2024/12/19 02:09:59 INFO : only1: Deleted 2024/12/19 02:09:59 INFO : only0: Deleted 2024/12/19 02:10:00 INFO : only8: Deleted 2024/12/19 02:10:00 INFO : only14: Deleted 2024/12/19 02:10:00 INFO : only4: Deleted 2024/12/19 02:10:00 INFO : only18: Deleted 2024/12/19 02:10:00 INFO : only7: Deleted 2024/12/19 02:10:00 INFO : only13: Deleted 2024/12/19 02:10:00 INFO : only12: Deleted 2024/12/19 02:10:00 INFO : only15: Deleted 2024/12/19 02:10:01 INFO : only19: Deleted 2024/12/19 02:10:01 INFO : only3: Deleted 2024/12/19 02:10:01 INFO : only6: Deleted 2024/12/19 02:10:01 INFO : only10: Deleted 2024/12/19 02:10:01 INFO : only17: Deleted 2024/12/19 02:10:01 INFO : only2: Deleted 2024/12/19 02:10:01 INFO : only5: Deleted 2024/12/19 02:10:02 INFO : only9: Deleted 2024/12/19 02:10:02 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-hixiwuz4newu'", Local "Local file system at /tmp/rclone3755433712", Modify Window "1ms" --- PASS: TestSyncConcurrentDelete (82.32s) === RUN TestSyncConcurrentTruncate run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-hixiwuz4newu'", Local "Local file system at /tmp/rclone3755433712", Modify Window "1ms" 2024/12/19 02:10:15 DEBUG : both0: md5 = 28522d994dc15584dda29c620d4bfd2e OK 2024/12/19 02:10:17 DEBUG : only0: md5 = 30ba24c28522293930084283e63871a6 OK 2024/12/19 02:10:19 DEBUG : both1: md5 = e00bd2ac2b35f41595caa67b24fd804a OK 2024/12/19 02:10:20 DEBUG : only1: md5 = eadba01c4b3ca724635fbcb00daff686 OK 2024/12/19 02:10:22 DEBUG : both2: md5 = 1e5189fddb4266a14b0f0158c2b02c1a OK 2024/12/19 02:10:24 DEBUG : only2: md5 = e83ef70010ab03c57e02e0cd3d557359 OK 2024/12/19 02:10:26 DEBUG : both3: md5 = b1555461b366948e5604f33fcc51f1c8 OK 2024/12/19 02:10:28 DEBUG : only3: md5 = 2acb79bf81f9a304502dc2676d54bc7a OK 2024/12/19 02:10:29 DEBUG : both4: md5 = bd6fca0f3a49d27ea8b1841ecf259c97 OK 2024/12/19 02:10:31 DEBUG : only4: md5 = 75d13758c5c5986510867e1aa4f187d3 OK 2024/12/19 02:10:32 DEBUG : both5: md5 = 604e789c4097e4ccbfd2b915a5fd8f6d OK 2024/12/19 02:10:34 DEBUG : only5: md5 = 8df21bf9cc6e7915781a03c781342866 OK 2024/12/19 02:10:35 DEBUG : both6: md5 = 41c62c6e33425adaa1dc5db9282b3186 OK 2024/12/19 02:10:37 DEBUG : only6: md5 = dac9231c459539508533aa07ffbff031 OK 2024/12/19 02:10:39 DEBUG : both7: md5 = e76380acc6e1c960734b7cbb96a8520b OK 2024/12/19 02:10:40 DEBUG : only7: md5 = 39cd822f0d82906606b069850443a539 OK 2024/12/19 02:10:42 DEBUG : both8: md5 = bc89f605de91122f205ce27790339538 OK 2024/12/19 02:10:44 DEBUG : only8: md5 = 1cc851d24cd3838136fcc3dbfa90603a OK 2024/12/19 02:10:45 DEBUG : both9: md5 = d55586ec9d1439787cf7dddb89a22201 OK 2024/12/19 02:10:47 DEBUG : only9: md5 = 43d9c720b2f84da2c28266b89eac6e9d OK 2024/12/19 02:10:49 DEBUG : both10: md5 = 8f3c240b3492a9828ab29d5b046d0812 OK 2024/12/19 02:10:50 DEBUG : only10: md5 = 74f5f7a49ced175d5a6b48daa7cd807a OK 2024/12/19 02:10:52 DEBUG : both11: md5 = 59ed96afa040c2c1c3e38960c73ed974 OK 2024/12/19 02:10:54 DEBUG : only11: md5 = 95c4652f72e2bec31b98dd78138abf2f OK 2024/12/19 02:10:55 DEBUG : both12: md5 = a4722b98e908d2ed9fb9f976d3117b73 OK 2024/12/19 02:10:57 DEBUG : only12: md5 = 576ab039726d5a5ae7ff504cdfc298e2 OK 2024/12/19 02:10:59 DEBUG : both13: md5 = e7da58d949c0f603090053a0833f12f5 OK 2024/12/19 02:11:01 DEBUG : only13: md5 = 005a74b4d426961b978050a5ebea1f43 OK 2024/12/19 02:11:02 DEBUG : both14: md5 = 690379c1a47c6a04992a342512b1ed2e OK 2024/12/19 02:11:04 DEBUG : only14: md5 = df57b6ea6ca98019b32eb5154eeab905 OK 2024/12/19 02:11:06 DEBUG : both15: md5 = 163bc32610f1e2b37883cc9a0d08c816 OK 2024/12/19 02:11:07 DEBUG : only15: md5 = abd6aa2b22a5f6bb642c0d8cb2ed0ac1 OK 2024/12/19 02:11:09 DEBUG : both16: md5 = 3e98c9dfb255f7c72f51115d7034ff4e OK 2024/12/19 02:11:11 DEBUG : only16: md5 = f4ca6e3bd7826fec9cc72862cf81f2a3 OK 2024/12/19 02:11:12 DEBUG : both17: md5 = a064505a7fed373573d10209e904152a OK 2024/12/19 02:11:14 DEBUG : only17: md5 = d4061b8aa645c9f2c927400360d93dec OK 2024/12/19 02:11:16 DEBUG : both18: md5 = ecd1173ea6afdbf7960c6450b7f35e2e OK 2024/12/19 02:11:18 DEBUG : only18: md5 = 003862ba26b44840b54b02a5c246d2f4 OK 2024/12/19 02:11:19 DEBUG : both19: md5 = 32eee309b430796ac12bc2360e57614c OK 2024/12/19 02:11:21 DEBUG : only19: md5 = bc428d882bebc36388c9f21695440376 OK 2024/12/19 02:11:21 DEBUG : both0: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2024/12/19 02:11:21 DEBUG : both10: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2024/12/19 02:11:21 DEBUG : both1: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2024/12/19 02:11:21 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hixiwuz4newu': Waiting for checks to finish 2024/12/19 02:11:21 DEBUG : both11: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2024/12/19 02:11:21 DEBUG : both0: Unchanged skipping 2024/12/19 02:11:21 DEBUG : both12: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2024/12/19 02:11:21 DEBUG : both12: Unchanged skipping 2024/12/19 02:11:21 DEBUG : both13: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2024/12/19 02:11:21 DEBUG : both13: Unchanged skipping 2024/12/19 02:11:21 DEBUG : both14: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2024/12/19 02:11:21 DEBUG : both14: Unchanged skipping 2024/12/19 02:11:21 DEBUG : both15: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2024/12/19 02:11:21 DEBUG : both15: Unchanged skipping 2024/12/19 02:11:21 DEBUG : both16: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2024/12/19 02:11:21 DEBUG : both16: Unchanged skipping 2024/12/19 02:11:21 DEBUG : both17: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2024/12/19 02:11:21 DEBUG : both10: Unchanged skipping 2024/12/19 02:11:21 DEBUG : both18: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2024/12/19 02:11:21 DEBUG : both1: Unchanged skipping 2024/12/19 02:11:21 DEBUG : both19: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2024/12/19 02:11:21 DEBUG : both11: Unchanged skipping 2024/12/19 02:11:21 DEBUG : both2: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2024/12/19 02:11:21 DEBUG : both17: Unchanged skipping 2024/12/19 02:11:21 DEBUG : both3: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2024/12/19 02:11:21 DEBUG : both3: Unchanged skipping 2024/12/19 02:11:21 DEBUG : both4: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2024/12/19 02:11:21 DEBUG : both4: Unchanged skipping 2024/12/19 02:11:21 DEBUG : both5: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2024/12/19 02:11:21 DEBUG : both5: Unchanged skipping 2024/12/19 02:11:21 DEBUG : both6: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2024/12/19 02:11:21 DEBUG : both18: Unchanged skipping 2024/12/19 02:11:21 DEBUG : both7: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2024/12/19 02:11:21 DEBUG : both7: Unchanged skipping 2024/12/19 02:11:21 DEBUG : both8: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2024/12/19 02:11:21 DEBUG : both8: Unchanged skipping 2024/12/19 02:11:21 DEBUG : both9: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2024/12/19 02:11:21 DEBUG : both19: Unchanged skipping 2024/12/19 02:11:21 DEBUG : only0: Sizes differ (src 0 vs dst 6) 2024/12/19 02:11:21 DEBUG : only1: Sizes differ (src 0 vs dst 6) 2024/12/19 02:11:21 DEBUG : only10: Sizes differ (src 0 vs dst 6) 2024/12/19 02:11:21 DEBUG : only11: Sizes differ (src 0 vs dst 6) 2024/12/19 02:11:21 DEBUG : only12: Sizes differ (src 0 vs dst 6) 2024/12/19 02:11:21 DEBUG : only13: Sizes differ (src 0 vs dst 6) 2024/12/19 02:11:21 DEBUG : only14: Sizes differ (src 0 vs dst 6) 2024/12/19 02:11:21 DEBUG : only15: Sizes differ (src 0 vs dst 6) 2024/12/19 02:11:21 DEBUG : only16: Sizes differ (src 0 vs dst 6) 2024/12/19 02:11:21 DEBUG : only17: Sizes differ (src 0 vs dst 6) 2024/12/19 02:11:21 DEBUG : only18: Sizes differ (src 0 vs dst 6) 2024/12/19 02:11:21 DEBUG : only19: Sizes differ (src 0 vs dst 6) 2024/12/19 02:11:21 DEBUG : only2: Sizes differ (src 0 vs dst 6) 2024/12/19 02:11:21 DEBUG : only3: Sizes differ (src 0 vs dst 6) 2024/12/19 02:11:21 DEBUG : only4: Sizes differ (src 0 vs dst 6) 2024/12/19 02:11:21 DEBUG : only5: Sizes differ (src 0 vs dst 6) 2024/12/19 02:11:21 DEBUG : only6: Sizes differ (src 0 vs dst 6) 2024/12/19 02:11:21 DEBUG : only7: Sizes differ (src 0 vs dst 6) 2024/12/19 02:11:21 DEBUG : only8: Sizes differ (src 0 vs dst 6) 2024/12/19 02:11:21 DEBUG : only9: Sizes differ (src 0 vs dst 6) 2024/12/19 02:11:21 DEBUG : both2: Unchanged skipping 2024/12/19 02:11:21 DEBUG : both6: Unchanged skipping 2024/12/19 02:11:21 DEBUG : both9: Unchanged skipping 2024/12/19 02:11:21 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hixiwuz4newu': Waiting for transfers to finish 2024/12/19 02:11:22 DEBUG : only11: md5 = f56852cf3470563ba9ef63ae18243883 OK 2024/12/19 02:11:22 INFO : only11: Copied (replaced existing) 2024/12/19 02:11:22 DEBUG : only10: md5 = 98a0678f2242e1cc7135d4ebfafe6210 OK 2024/12/19 02:11:22 INFO : only10: Copied (replaced existing) 2024/12/19 02:11:23 DEBUG : only1: md5 = a86810492a9208e6e8b7941e2b1c740d OK 2024/12/19 02:11:23 INFO : only1: Copied (replaced existing) 2024/12/19 02:11:23 DEBUG : only0: md5 = 4d31482680f0cc86228b54df2569f018 OK 2024/12/19 02:11:23 INFO : only0: Copied (replaced existing) 2024/12/19 02:11:24 DEBUG : only13: md5 = a41726ebc36a8153909e259731014a2b OK 2024/12/19 02:11:24 INFO : only13: Copied (replaced existing) 2024/12/19 02:11:24 DEBUG : only12: md5 = ecd65a5054c254fa48df993a64e9cccc OK 2024/12/19 02:11:24 INFO : only12: Copied (replaced existing) 2024/12/19 02:11:24 DEBUG : only14: md5 = 97f7e0cd113a115c09b1b11b2b3604e0 OK 2024/12/19 02:11:24 INFO : only14: Copied (replaced existing) 2024/12/19 02:11:24 DEBUG : only15: md5 = 72b24d856b4fc9df628456c9e5ce546d OK 2024/12/19 02:11:24 INFO : only15: Copied (replaced existing) 2024/12/19 02:11:25 DEBUG : only17: md5 = 4444fd857710ec98d18f30a9c0b50876 OK 2024/12/19 02:11:25 INFO : only17: Copied (replaced existing) 2024/12/19 02:11:25 DEBUG : only16: md5 = 6e91c1948f34387e131030979a52c7d0 OK 2024/12/19 02:11:25 INFO : only16: Copied (replaced existing) 2024/12/19 02:11:25 DEBUG : only19: md5 = da1ac7950daf868036121b1582ed4d26 OK 2024/12/19 02:11:25 INFO : only19: Copied (replaced existing) 2024/12/19 02:11:25 DEBUG : only18: md5 = 96da30fc8c76ad90750ae342771efc77 OK 2024/12/19 02:11:25 INFO : only18: Copied (replaced existing) 2024/12/19 02:11:26 DEBUG : only2: md5 = 5021cc7821fa63c61b834d64745d7e9f OK 2024/12/19 02:11:26 INFO : only2: Copied (replaced existing) 2024/12/19 02:11:27 DEBUG : only3: md5 = 2310dd7c58247ff54cfe92c99ec0a60c OK 2024/12/19 02:11:27 INFO : only3: Copied (replaced existing) 2024/12/19 02:11:27 DEBUG : only4: md5 = f4b3bb43ca0ddd579c6644c3adf5bcf9 OK 2024/12/19 02:11:27 INFO : only4: Copied (replaced existing) 2024/12/19 02:11:27 DEBUG : only5: md5 = 05a6269234494a996ad9edbbc5007c83 OK 2024/12/19 02:11:27 INFO : only5: Copied (replaced existing) 2024/12/19 02:11:27 DEBUG : only6: md5 = 6e51ddfe031bcfa0a9ad2ee3480aa77a OK 2024/12/19 02:11:27 INFO : only6: Copied (replaced existing) 2024/12/19 02:11:28 DEBUG : only9: md5 = df00f11ad612b911bb104837ab59f781 OK 2024/12/19 02:11:28 INFO : only9: Copied (replaced existing) 2024/12/19 02:11:28 DEBUG : only8: md5 = 6630573c167d2cdd62bbd9df4eb10d43 OK 2024/12/19 02:11:28 INFO : only8: Copied (replaced existing) 2024/12/19 02:11:28 DEBUG : only7: md5 = 27de3bb730d48c34f349f595e1c59e28 OK 2024/12/19 02:11:28 INFO : only7: Copied (replaced existing) 2024/12/19 02:11:28 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-hixiwuz4newu'", Local "Local file system at /tmp/rclone3755433712", Modify Window "1ms" --- PASS: TestSyncConcurrentTruncate (97.72s) === RUN TestNothingToTransferWithEmptyDirs run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-hixiwuz4newu'", Local "Local file system at /tmp/rclone3755433712", Modify Window "1ms" 2024/12/19 02:11:51 INFO : sub dir: Set directory modification time (using DirSetModTime) 2024/12/19 02:11:51 DEBUG : sub dir: Making directory with metadata 2024/12/19 02:11:52 INFO : sub dir: Made directory with metadata (mtime=2011-12-30T12:59:59Z) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-hixiwuz4newu'", Local "Local file system at /tmp/rclone3755433712", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-hixiwuz4newu'", Local "Local file system at /tmp/rclone3755433712", Modify Window "1ms" 2024/12/19 02:12:13 INFO : sub dir2: Set directory modification time (using DirSetModTime) 2024/12/19 02:12:13 INFO : sub dir2: Set directory modification time (using DirSetModTime) 2024/12/19 02:12:13 INFO : sub dirEmpty/sub dirEmpty2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2024/12/19 02:12:13 INFO : sub dirEmpty: Set directory modification time (using DirSetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-hixiwuz4newu'", Local "Local file system at /tmp/rclone3755433712", Modify Window "1ms" 2024/12/19 02:12:27 DEBUG : gcsdkq814sbtppue42dpsbg8ug: Rmdir: contains trashed file: "sjuo65gk5q3r1199jselk9k9o0" 2024/12/19 02:12:28 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/37qp6d1gohacv723ij3brofbu8/i24n0ln37pa2hv8pctddeuh73o: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" 2024/12/19 02:12:28 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/37qp6d1gohacv723ij3brofbu8: Rmdir: contains trashed file: "i24n0ln37pa2hv8pctddeuh73o" 2024/12/19 02:12:29 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "37qp6d1gohacv723ij3brofbu8" 2024/12/19 02:12:30 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak" 2024/12/19 02:12:31 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak" 2024/12/19 02:12:32 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak" 2024/12/19 02:12:33 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak" 2024/12/19 02:12:34 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/4r13oncfa2rsrr82oqhsqv24ns: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" 2024/12/19 02:12:34 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc: Rmdir: contains trashed file: "4r13oncfa2rsrr82oqhsqv24ns" 2024/12/19 02:12:34 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak" 2024/12/19 02:12:35 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestNothingToTransferWithEmptyDirs (46.00s) === RUN TestNothingToTransferWithoutEmptyDirs run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-hixiwuz4newu'", Local "Local file system at /tmp/rclone3755433712", Modify Window "1ms" 2024/12/19 02:12:37 INFO : sub dir: Set directory modification time (using DirSetModTime) 2024/12/19 02:12:37 DEBUG : sub dir: Making directory with metadata 2024/12/19 02:12:38 INFO : sub dir: Made directory with metadata (mtime=2011-12-30T12:59:59Z) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-hixiwuz4newu'", Local "Local file system at /tmp/rclone3755433712", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-hixiwuz4newu'", Local "Local file system at /tmp/rclone3755433712", Modify Window "1ms" 2024/12/19 02:13:04 INFO : sub dir2: Set directory modification time (using DirSetModTime) 2024/12/19 02:13:05 INFO : sub dir2: Set directory modification time (using DirSetModTime) 2024/12/19 02:13:05 INFO : sub dirEmpty/sub dirEmpty2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2024/12/19 02:13:05 INFO : sub dirEmpty: Set directory modification time (using DirSetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-hixiwuz4newu'", Local "Local file system at /tmp/rclone3755433712", Modify Window "1ms" 2024/12/19 02:13:17 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/37qp6d1gohacv723ij3brofbu8/i24n0ln37pa2hv8pctddeuh73o: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" 2024/12/19 02:13:18 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/37qp6d1gohacv723ij3brofbu8: Rmdir: contains trashed file: "i24n0ln37pa2hv8pctddeuh73o" 2024/12/19 02:13:19 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "37qp6d1gohacv723ij3brofbu8" 2024/12/19 02:13:19 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak" 2024/12/19 02:13:20 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak" 2024/12/19 02:13:21 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak" 2024/12/19 02:13:22 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak" 2024/12/19 02:13:23 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/4r13oncfa2rsrr82oqhsqv24ns: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" 2024/12/19 02:13:24 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc: Rmdir: contains trashed file: "4r13oncfa2rsrr82oqhsqv24ns" 2024/12/19 02:13:24 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak" 2024/12/19 02:13:25 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestNothingToTransferWithoutEmptyDirs (49.18s) PASS 2024/12/19 02:13:27 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hixiwuz4newu': Purge remote "./sync.test -test.v -test.timeout 1h0m0s -remote TestCryptDrive: -verbose" - Finished OK in 17m42.553752442s (try 1/5)