"./sync.test -test.v -test.timeout 1h0m0s -remote TestCryptDrive: -verbose" - Starting (try 1/5) 2024/12/13 01:21:09 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-nuguwer9fuxa" 2024/12/13 01:21:09 DEBUG : Using config file from "/home/rclone/.rclone.conf" 2024/12/13 01:21:09 DEBUG : Creating backend with remote "TestDrive:crypt/sinc28mqh1lj92nob4gqgdh328leac69b1ffmoeuv12ubd3d6640" 2024/12/13 01:21:10 DEBUG : Creating backend with remote "/tmp/rclone588269293" === RUN TestPipe --- PASS: TestPipe (0.00s) === RUN TestPipeConcurrent --- PASS: TestPipeConcurrent (0.03s) === RUN TestPipeOrderBy === RUN TestPipeOrderBy/#00 === RUN TestPipeOrderBy/size === RUN TestPipeOrderBy/name === RUN TestPipeOrderBy/modtime === RUN TestPipeOrderBy/size,ascending === RUN TestPipeOrderBy/name,asc === RUN TestPipeOrderBy/modtime,ascending === RUN TestPipeOrderBy/size,descending === RUN TestPipeOrderBy/name,desc === RUN TestPipeOrderBy/modtime,descending === RUN TestPipeOrderBy/size,mixed,50 === RUN TestPipeOrderBy/size,mixed,51 --- PASS: TestPipeOrderBy (0.00s) --- PASS: TestPipeOrderBy/#00 (0.00s) --- PASS: TestPipeOrderBy/size (0.00s) --- PASS: TestPipeOrderBy/name (0.00s) --- PASS: TestPipeOrderBy/modtime (0.00s) --- PASS: TestPipeOrderBy/size,ascending (0.00s) --- PASS: TestPipeOrderBy/name,asc (0.00s) --- PASS: TestPipeOrderBy/modtime,ascending (0.00s) --- PASS: TestPipeOrderBy/size,descending (0.00s) --- PASS: TestPipeOrderBy/name,desc (0.00s) --- PASS: TestPipeOrderBy/modtime,descending (0.00s) --- PASS: TestPipeOrderBy/size,mixed,50 (0.00s) --- PASS: TestPipeOrderBy/size,mixed,51 (0.00s) === RUN TestNewLess === RUN TestNewLess/blankOK === RUN TestNewLess/tooManyParts === RUN TestNewLess/tooManyParts2 === RUN TestNewLess/badMixed === RUN TestNewLess/unknownComparison === RUN TestNewLess/unknownSortDirection === RUN TestNewLess/size === RUN TestNewLess/name === RUN TestNewLess/modtime === RUN TestNewLess/size,ascending === RUN TestNewLess/name,asc === RUN TestNewLess/modtime,ascending === RUN TestNewLess/size,descending === RUN TestNewLess/name,desc === RUN TestNewLess/modtime,descending === RUN TestNewLess/modtime,mixed === RUN TestNewLess/modtime,mixed,30 --- PASS: TestNewLess (0.00s) --- PASS: TestNewLess/blankOK (0.00s) --- PASS: TestNewLess/tooManyParts (0.00s) --- PASS: TestNewLess/tooManyParts2 (0.00s) --- PASS: TestNewLess/badMixed (0.00s) --- PASS: TestNewLess/unknownComparison (0.00s) --- PASS: TestNewLess/unknownSortDirection (0.00s) --- PASS: TestNewLess/size (0.00s) --- PASS: TestNewLess/name (0.00s) --- PASS: TestNewLess/modtime (0.00s) --- PASS: TestNewLess/size,ascending (0.00s) --- PASS: TestNewLess/name,asc (0.00s) --- PASS: TestNewLess/modtime,ascending (0.00s) --- PASS: TestNewLess/size,descending (0.00s) --- PASS: TestNewLess/name,desc (0.00s) --- PASS: TestNewLess/modtime,descending (0.00s) --- PASS: TestNewLess/modtime,mixed (0.00s) --- PASS: TestNewLess/modtime,mixed,30 (0.00s) === RUN TestRcCopy rc_test.go:16: Skipping test on non local remote --- SKIP: TestRcCopy (0.00s) === RUN TestRcMove rc_test.go:16: Skipping test on non local remote --- SKIP: TestRcMove (0.00s) === RUN TestRcSync rc_test.go:16: Skipping test on non local remote --- SKIP: TestRcSync (0.00s) === RUN TestCopyWithDryRun run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-nuguwer9fuxa'", Local "Local file system at /tmp/rclone588269293", Modify Window "1ms" 2024/12/13 01:21:12 DEBUG : Added delayed dir = "sub dir", newDst= 2024/12/13 01:21:12 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2024/12/13 01:21:12 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-nuguwer9fuxa': Waiting for checks to finish 2024/12/13 01:21:12 NOTICE: sub dir/hello world: Skipped copy as --dry-run is set (size 11) 2024/12/13 01:21:12 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-nuguwer9fuxa': Waiting for transfers to finish 2024/12/13 01:21:12 NOTICE: sub dir: Skipped set directory modification time as --dry-run is set run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-nuguwer9fuxa'", Local "Local file system at /tmp/rclone588269293", Modify Window "1ms" --- PASS: TestCopyWithDryRun (2.67s) === RUN TestCopy run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-nuguwer9fuxa'", Local "Local file system at /tmp/rclone588269293", Modify Window "1ms" 2024/12/13 01:21:13 INFO : sub dir: Set directory modification time (using DirSetModTime) 2024/12/13 01:21:13 DEBUG : Added delayed dir = "sub dir", newDst= 2024/12/13 01:21:13 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2024/12/13 01:21:13 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-nuguwer9fuxa': Waiting for checks to finish 2024/12/13 01:21:13 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-nuguwer9fuxa': Waiting for transfers to finish 2024/12/13 01:21:16 DEBUG : sub dir/hello world: md5 = 32c005cd0399dc5810a4d22a23bdd070 OK 2024/12/13 01:21:16 INFO : sub dir/hello world: Copied (new) 2024/12/13 01:21:17 INFO : sub dir: Set directory modification time (using DirSetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-nuguwer9fuxa'", Local "Local file system at /tmp/rclone588269293", Modify Window "1ms" 2024/12/13 01:21:19 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestCopy (6.88s) === RUN TestCopyMetadata run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-nuguwer9fuxa'", Local "Local file system at /tmp/rclone588269293", Modify Window "1ms" 2024/12/13 01:21:20 DEBUG : metadata sub dir: Making directory with metadata 2024/12/13 01:21:20 INFO : metadata sub dir: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2024/12/13 01:21:20 DEBUG : empty metadata sub dir: Making directory with metadata 2024/12/13 01:21:20 INFO : empty metadata sub dir: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2024/12/13 01:21:20 DEBUG : Local file system at /tmp/rclone588269293: File to upload is small (21 bytes), uploading instead of streaming 2024/12/13 01:21:20 DEBUG : metadata sub dir/hello metadata world: md5 = baa7a013449dbba2b1ed02b5cfb4e1a2 OK 2024/12/13 01:21:20 DEBUG : metadata sub dir/hello metadata world: Size and md5 of src and dst objects identical 2024/12/13 01:21:20 INFO : metadata sub dir: Set directory modification time (using DirSetModTime) 2024/12/13 01:21:20 DEBUG : Google drive root 'crypt/sinc28mqh1lj92nob4gqgdh328leac69b1ffmoeuv12ubd3d6640': Skipping btime metadata as can't update it on an existing file: 2024-12-13T01:21:20.429234695Z 2024/12/13 01:21:21 INFO : empty metadata sub dir: Updated directory metadata 2024/12/13 01:21:22 DEBUG : Google drive root 'crypt/sinc28mqh1lj92nob4gqgdh328leac69b1ffmoeuv12ubd3d6640': Skipping btime metadata as can't update it on an existing file: 2024-12-13T01:21:20.429234695Z 2024/12/13 01:21:22 INFO : metadata sub dir: Updated directory metadata 2024/12/13 01:21:22 DEBUG : metadata sub dir/hello metadata world: Need to transfer - File not found at Destination 2024/12/13 01:21:22 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-nuguwer9fuxa': Waiting for checks to finish 2024/12/13 01:21:22 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-nuguwer9fuxa': Waiting for transfers to finish 2024/12/13 01:21:24 DEBUG : metadata sub dir/hello metadata world: md5 = 01e2bc04b2f6a2b5240ed8f64e5011d4 OK 2024/12/13 01:21:24 INFO : metadata sub dir/hello metadata world: Copied (new) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-nuguwer9fuxa'", Local "Local file system at /tmp/rclone588269293", Modify Window "1ms" 2024/12/13 01:21:27 DEBUG : fg45q1rm3kh00nmmkk4m6ihmrcnel1p7551kqhjr9bk2gtd2gbf0: Rmdir: contains trashed file: "dmuvulfij81f693ur0f1vvbvq9v6iscp56daas3m51n9li5e3470" --- PASS: TestCopyMetadata (9.30s) === RUN TestCopyMetadataNoEmptyDirs run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-nuguwer9fuxa'", Local "Local file system at /tmp/rclone588269293", Modify Window "1ms" 2024/12/13 01:21:29 DEBUG : metadata sub dir: Making directory with metadata 2024/12/13 01:21:29 INFO : metadata sub dir: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2024/12/13 01:21:29 DEBUG : empty metadata sub dir: Making directory with metadata 2024/12/13 01:21:29 INFO : empty metadata sub dir: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2024/12/13 01:21:29 DEBUG : Local file system at /tmp/rclone588269293: File to upload is small (21 bytes), uploading instead of streaming 2024/12/13 01:21:29 DEBUG : metadata sub dir/hello metadata world: md5 = baa7a013449dbba2b1ed02b5cfb4e1a2 OK 2024/12/13 01:21:29 DEBUG : metadata sub dir/hello metadata world: Size and md5 of src and dst objects identical 2024/12/13 01:21:29 INFO : metadata sub dir: Set directory modification time (using DirSetModTime) 2024/12/13 01:21:29 DEBUG : Added delayed dir = "empty metadata sub dir", newDst= 2024/12/13 01:21:29 DEBUG : Added delayed dir = "metadata sub dir", newDst= 2024/12/13 01:21:29 DEBUG : metadata sub dir/hello metadata world: Need to transfer - File not found at Destination 2024/12/13 01:21:29 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-nuguwer9fuxa': Waiting for checks to finish 2024/12/13 01:21:29 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-nuguwer9fuxa': Waiting for transfers to finish 2024/12/13 01:21:32 DEBUG : metadata sub dir/hello metadata world: md5 = 5f313cc32ba2369a72b39c45ab19a722 OK 2024/12/13 01:21:32 INFO : metadata sub dir/hello metadata world: Copied (new) 2024/12/13 01:21:32 DEBUG : Google drive root 'crypt/sinc28mqh1lj92nob4gqgdh328leac69b1ffmoeuv12ubd3d6640': Skipping btime metadata as can't update it on an existing file: 2024-12-13T01:21:29.729147558Z 2024/12/13 01:21:33 INFO : metadata sub dir: Updated directory metadata run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-nuguwer9fuxa'", Local "Local file system at /tmp/rclone588269293", Modify Window "1ms" 2024/12/13 01:21:36 DEBUG : fg45q1rm3kh00nmmkk4m6ihmrcnel1p7551kqhjr9bk2gtd2gbf0: Rmdir: contains trashed file: "dmuvulfij81f693ur0f1vvbvq9v6iscp56daas3m51n9li5e3470" --- PASS: TestCopyMetadataNoEmptyDirs (7.86s) === RUN TestCopyMissingDirectory run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-nuguwer9fuxa'", Local "Local file system at /tmp/rclone588269293", Modify Window "1ms" 2024/12/13 01:21:37 DEBUG : Creating backend with remote "/non-existing" 2024/12/13 01:21:37 ERROR : Local file system at /non-existing: error reading source root directory: directory not found 2024/12/13 01:21:37 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-nuguwer9fuxa': Waiting for checks to finish 2024/12/13 01:21:37 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-nuguwer9fuxa': Waiting for transfers to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-nuguwer9fuxa'", Local "Local file system at /tmp/rclone588269293", Modify Window "1ms" --- PASS: TestCopyMissingDirectory (1.11s) === RUN TestCopyNoTraverse run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-nuguwer9fuxa'", Local "Local file system at /tmp/rclone588269293", Modify Window "1ms" 2024/12/13 01:21:38 DEBUG : Added delayed dir = "sub dir", newDst= 2024/12/13 01:21:38 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2024/12/13 01:21:38 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-nuguwer9fuxa': Waiting for checks to finish 2024/12/13 01:21:38 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-nuguwer9fuxa': Waiting for transfers to finish 2024/12/13 01:21:41 DEBUG : sub dir/hello world: md5 = ad5da183e433ff40c1f3c991b0360de4 OK 2024/12/13 01:21:41 INFO : sub dir/hello world: Copied (new) 2024/12/13 01:21:42 INFO : sub dir: Set directory modification time (using DirSetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-nuguwer9fuxa'", Local "Local file system at /tmp/rclone588269293", Modify Window "1ms" 2024/12/13 01:21:44 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestCopyNoTraverse (7.10s) === RUN TestCopyCheckFirst run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-nuguwer9fuxa'", Local "Local file system at /tmp/rclone588269293", Modify Window "1ms" 2024/12/13 01:21:45 INFO : Encrypted drive 'TestCryptDrive:rclone-test-nuguwer9fuxa': Running all checks before starting transfers 2024/12/13 01:21:46 DEBUG : Added delayed dir = "sub dir", newDst= 2024/12/13 01:21:46 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2024/12/13 01:21:46 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-nuguwer9fuxa': Waiting for checks to finish 2024/12/13 01:21:46 INFO : Encrypted drive 'TestCryptDrive:rclone-test-nuguwer9fuxa': Checks finished, now starting transfers 2024/12/13 01:21:46 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-nuguwer9fuxa': Waiting for transfers to finish 2024/12/13 01:21:48 DEBUG : sub dir/hello world: md5 = df2782d943fa08a260a7e97acb3df434 OK 2024/12/13 01:21:48 INFO : sub dir/hello world: Copied (new) 2024/12/13 01:21:49 INFO : sub dir: Set directory modification time (using DirSetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-nuguwer9fuxa'", Local "Local file system at /tmp/rclone588269293", Modify Window "1ms" 2024/12/13 01:21:51 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" 2024/12/13 01:21:52 DEBUG : Config file has changed externally - reloading 2024/12/13 01:21:52 DEBUG : TestDrive: Loaded fresh token from config file --- PASS: TestCopyCheckFirst (7.34s) === RUN TestSyncNoTraverse run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-nuguwer9fuxa'", Local "Local file system at /tmp/rclone588269293", Modify Window "1ms" 2024/12/13 01:21:53 ERROR : Ignoring --no-traverse with sync 2024/12/13 01:21:53 DEBUG : Added delayed dir = "sub dir", newDst= 2024/12/13 01:21:53 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2024/12/13 01:21:53 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-nuguwer9fuxa': Waiting for checks to finish 2024/12/13 01:21:53 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-nuguwer9fuxa': Waiting for transfers to finish 2024/12/13 01:21:56 DEBUG : sub dir/hello world: md5 = 51e72690bd3b2dce258d3261f4e2b83e OK 2024/12/13 01:21:56 INFO : sub dir/hello world: Copied (new) 2024/12/13 01:21:56 DEBUG : Waiting for deletions to finish 2024/12/13 01:21:56 INFO : sub dir: Set directory modification time (using DirSetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-nuguwer9fuxa'", Local "Local file system at /tmp/rclone588269293", Modify Window "1ms" 2024/12/13 01:21:58 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestSyncNoTraverse (6.82s) === RUN TestCopyWithDepth run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-nuguwer9fuxa'", Local "Local file system at /tmp/rclone588269293", Modify Window "1ms" 2024/12/13 01:22:00 DEBUG : hello world2: Need to transfer - File not found at Destination 2024/12/13 01:22:00 DEBUG : Added delayed dir = "sub dir", newDst= 2024/12/13 01:22:00 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-nuguwer9fuxa': Waiting for checks to finish 2024/12/13 01:22:00 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-nuguwer9fuxa': Waiting for transfers to finish 2024/12/13 01:22:01 DEBUG : hello world2: md5 = 9fe9168429ba365fb80f3d614f59ff8b OK 2024/12/13 01:22:01 INFO : hello world2: Copied (new) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-nuguwer9fuxa'", Local "Local file system at /tmp/rclone588269293", Modify Window "1ms" --- PASS: TestCopyWithDepth (3.62s) === RUN TestCopyWithFilesFrom run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-nuguwer9fuxa'", Local "Local file system at /tmp/rclone588269293", Modify Window "1ms" 2024/12/13 01:22:03 DEBUG : potato2: Need to transfer - File not found at Destination 2024/12/13 01:22:03 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-nuguwer9fuxa': Waiting for checks to finish 2024/12/13 01:22:03 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-nuguwer9fuxa': Waiting for transfers to finish 2024/12/13 01:22:05 DEBUG : potato2: md5 = 6fa06d839085066ac347a6c319952975 OK 2024/12/13 01:22:05 INFO : potato2: Copied (new) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-nuguwer9fuxa'", Local "Local file system at /tmp/rclone588269293", Modify Window "1ms" --- PASS: TestCopyWithFilesFrom (3.58s) === RUN TestCopyWithFilesFromAndNoTraverse run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-nuguwer9fuxa'", Local "Local file system at /tmp/rclone588269293", Modify Window "1ms" 2024/12/13 01:22:07 DEBUG : potato2: Need to transfer - File not found at Destination 2024/12/13 01:22:07 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-nuguwer9fuxa': Waiting for checks to finish 2024/12/13 01:22:07 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-nuguwer9fuxa': Waiting for transfers to finish 2024/12/13 01:22:08 DEBUG : potato2: md5 = bb9c7fa7597d96799cedb6d5d87b3887 OK 2024/12/13 01:22:08 INFO : potato2: Copied (new) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-nuguwer9fuxa'", Local "Local file system at /tmp/rclone588269293", Modify Window "1ms" --- PASS: TestCopyWithFilesFromAndNoTraverse (3.53s) === RUN TestCopyEmptyDirectories run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-nuguwer9fuxa'", Local "Local file system at /tmp/rclone588269293", Modify Window "1ms" 2024/12/13 01:22:10 DEBUG : sub dir2/sub sub dir2: Making directory with metadata 2024/12/13 01:22:10 INFO : sub dir2/sub sub dir2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2024/12/13 01:22:10 INFO : sub dir2: Set directory modification time (using DirSetModTime) 2024/12/13 01:22:10 INFO : sub dir: Set directory modification time (using DirSetModTime) 2024/12/13 01:22:10 DEBUG : sub dir: Making directory with metadata 2024/12/13 01:22:11 INFO : sub dir: Made directory with metadata (mtime=2001-02-03T04:05:06.499999999Z) 2024/12/13 01:22:11 DEBUG : sub dir2: Making directory with metadata 2024/12/13 01:22:13 INFO : sub dir2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2024/12/13 01:22:13 DEBUG : sub dir2/sub sub dir2: Making directory with metadata 2024/12/13 01:22:13 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2024/12/13 01:22:14 INFO : sub dir2/sub sub dir2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2024/12/13 01:22:14 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-nuguwer9fuxa': Waiting for checks to finish 2024/12/13 01:22:14 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-nuguwer9fuxa': Waiting for transfers to finish 2024/12/13 01:22:14 DEBUG : sub dir/hello world: md5 = feb2df1e5d51f7751506a19dc416d402 OK 2024/12/13 01:22:14 INFO : sub dir/hello world: Copied (new) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-nuguwer9fuxa'", Local "Local file system at /tmp/rclone588269293", Modify Window "1ms" 2024/12/13 01:22:18 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc: Rmdir: contains trashed file: "cv6a9uf28ngrajena8kt5ijjn0" 2024/12/13 01:22:19 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestCopyEmptyDirectories (10.52s) === RUN TestCopyNoEmptyDirectories run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-nuguwer9fuxa'", Local "Local file system at /tmp/rclone588269293", Modify Window "1ms" 2024/12/13 01:22:21 DEBUG : sub dir2: Making directory 2024/12/13 01:22:21 DEBUG : sub dir2/sub sub dir2: Making directory with metadata 2024/12/13 01:22:21 INFO : sub dir2/sub sub dir2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2024/12/13 01:22:21 DEBUG : Added delayed dir = "sub dir", newDst= 2024/12/13 01:22:21 DEBUG : Added delayed dir = "sub dir2", newDst= 2024/12/13 01:22:21 DEBUG : Added delayed dir = "sub dir2/sub sub dir2", newDst= 2024/12/13 01:22:21 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2024/12/13 01:22:21 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-nuguwer9fuxa': Waiting for checks to finish 2024/12/13 01:22:21 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-nuguwer9fuxa': Waiting for transfers to finish 2024/12/13 01:22:24 DEBUG : sub dir/hello world: md5 = ea76f10114fc147b92116dea9d66f898 OK 2024/12/13 01:22:24 INFO : sub dir/hello world: Copied (new) 2024/12/13 01:22:25 INFO : sub dir: Set directory modification time (using DirSetModTime) 2024/12/13 01:22:27 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestCopyNoEmptyDirectories (6.65s) === RUN TestMoveEmptyDirectories run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-nuguwer9fuxa'", Local "Local file system at /tmp/rclone588269293", Modify Window "1ms" 2024/12/13 01:22:27 DEBUG : sub dir2: Making directory with metadata 2024/12/13 01:22:27 INFO : sub dir2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2024/12/13 01:22:28 DEBUG : sub dir: Making directory with metadata 2024/12/13 01:22:29 INFO : sub dir: Made directory with metadata (mtime=2024-12-13T01:22:27.852605219Z) 2024/12/13 01:22:29 DEBUG : sub dir2: Making directory with metadata 2024/12/13 01:22:30 INFO : sub dir2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2024/12/13 01:22:30 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2024/12/13 01:22:30 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-nuguwer9fuxa': Waiting for checks to finish 2024/12/13 01:22:30 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-nuguwer9fuxa': Waiting for transfers to finish 2024/12/13 01:22:31 DEBUG : sub dir/hello world: md5 = 8d79f6dc3554bc5620a2bda3fd5d8e4e OK 2024/12/13 01:22:31 INFO : sub dir/hello world: Copied (new) 2024/12/13 01:22:31 INFO : sub dir/hello world: Deleted run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-nuguwer9fuxa'", Local "Local file system at /tmp/rclone588269293", Modify Window "1ms" 2024/12/13 01:22:35 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestMoveEmptyDirectories (8.71s) === RUN TestSyncNoUpdateDirModtime run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-nuguwer9fuxa'", Local "Local file system at /tmp/rclone588269293", Modify Window "1ms" 2024/12/13 01:22:36 DEBUG : sub dir no update dir modtime: Making directory with metadata 2024/12/13 01:22:36 INFO : sub dir no update dir modtime: Made directory with metadata (mtime=2001-02-03T04:05:06.499999999Z) 2024/12/13 01:22:38 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-nuguwer9fuxa': Waiting for checks to finish 2024/12/13 01:22:38 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-nuguwer9fuxa': Waiting for transfers to finish 2024/12/13 01:22:38 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-nuguwer9fuxa'", Local "Local file system at /tmp/rclone588269293", Modify Window "1ms" --- PASS: TestSyncNoUpdateDirModtime (4.40s) === RUN TestMoveNoEmptyDirectories run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-nuguwer9fuxa'", Local "Local file system at /tmp/rclone588269293", Modify Window "1ms" 2024/12/13 01:22:40 DEBUG : sub dir2: Making directory 2024/12/13 01:22:41 DEBUG : Added delayed dir = "sub dir", newDst= 2024/12/13 01:22:41 DEBUG : Added delayed dir = "sub dir2", newDst= 2024/12/13 01:22:41 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2024/12/13 01:22:41 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-nuguwer9fuxa': Waiting for checks to finish 2024/12/13 01:22:41 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-nuguwer9fuxa': Waiting for transfers to finish 2024/12/13 01:22:44 DEBUG : sub dir/hello world: md5 = 719dba4e584f3fbb0a92b12a12f52cfe OK 2024/12/13 01:22:44 INFO : sub dir/hello world: Copied (new) 2024/12/13 01:22:44 INFO : sub dir/hello world: Deleted 2024/12/13 01:22:44 INFO : sub dir: Set directory modification time (using DirSetModTime) 2024/12/13 01:22:46 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestMoveNoEmptyDirectories (6.32s) === RUN TestSyncEmptyDirectories run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-nuguwer9fuxa'", Local "Local file system at /tmp/rclone588269293", Modify Window "1ms" 2024/12/13 01:22:47 DEBUG : sub dir2: Making directory with metadata 2024/12/13 01:22:47 INFO : sub dir2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2024/12/13 01:22:47 INFO : sub dir: Set directory modification time (using DirSetModTime) 2024/12/13 01:22:47 DEBUG : sub dir: Making directory with metadata 2024/12/13 01:22:48 INFO : sub dir: Made directory with metadata (mtime=2001-02-03T04:05:06.499999999Z) 2024/12/13 01:22:48 DEBUG : sub dir2: Making directory with metadata 2024/12/13 01:22:49 INFO : sub dir2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2024/12/13 01:22:49 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2024/12/13 01:22:49 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-nuguwer9fuxa': Waiting for checks to finish 2024/12/13 01:22:49 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-nuguwer9fuxa': Waiting for transfers to finish 2024/12/13 01:22:51 DEBUG : sub dir/hello world: md5 = e5d188fcc1429425a9e8affc13765da5 OK 2024/12/13 01:22:51 INFO : sub dir/hello world: Copied (new) 2024/12/13 01:22:51 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-nuguwer9fuxa'", Local "Local file system at /tmp/rclone588269293", Modify Window "1ms" 2024/12/13 01:22:54 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestSyncEmptyDirectories (8.74s) === RUN TestSyncSetDelayedModTimes run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-nuguwer9fuxa'", Local "Local file system at /tmp/rclone588269293", Modify Window "1ms" sync_test.go:507: Backend doesn't have DirModTimeUpdatesOnWrite set --- SKIP: TestSyncSetDelayedModTimes (0.43s) === RUN TestSyncNoEmptyDirectories run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-nuguwer9fuxa'", Local "Local file system at /tmp/rclone588269293", Modify Window "1ms" 2024/12/13 01:22:56 DEBUG : sub dir2: Making directory 2024/12/13 01:22:56 DEBUG : Added delayed dir = "sub dir", newDst= 2024/12/13 01:22:56 DEBUG : Added delayed dir = "sub dir2", newDst= 2024/12/13 01:22:56 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2024/12/13 01:22:56 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-nuguwer9fuxa': Waiting for checks to finish 2024/12/13 01:22:56 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-nuguwer9fuxa': Waiting for transfers to finish 2024/12/13 01:22:59 DEBUG : sub dir/hello world: md5 = e692175b16dffe5da91d565a2a322fd5 OK 2024/12/13 01:22:59 INFO : sub dir/hello world: Copied (new) 2024/12/13 01:22:59 DEBUG : Waiting for deletions to finish 2024/12/13 01:22:59 INFO : sub dir: Set directory modification time (using DirSetModTime) 2024/12/13 01:23:01 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestSyncNoEmptyDirectories (6.05s) === RUN TestServerSideCopy run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-nuguwer9fuxa'", Local "Local file system at /tmp/rclone588269293", Modify Window "1ms" 2024/12/13 01:23:05 DEBUG : sub dir/hello world: md5 = 2ee1bae70b14c44eb08502f21e94d750 OK 2024/12/13 01:23:06 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-luselom2bavo" 2024/12/13 01:23:06 DEBUG : Config file has changed externally - reloading 2024/12/13 01:23:06 DEBUG : Creating backend with remote "TestDrive:crypt/innsn11tvg19sq72eck6dv1vr5212kvnhbj5an45qq5176i34l90" sync_test.go:590: Server side copy (if possible) Encrypted drive 'TestCryptDrive:rclone-test-nuguwer9fuxa' -> Encrypted drive 'TestCryptDrive:rclone-test-luselom2bavo' 2024/12/13 01:23:07 DEBUG : Added delayed dir = "sub dir", newDst= 2024/12/13 01:23:07 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2024/12/13 01:23:07 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-luselom2bavo': Waiting for checks to finish 2024/12/13 01:23:07 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-luselom2bavo': Waiting for transfers to finish 2024/12/13 01:23:11 INFO : sub dir/hello world: Copied (server-side copy) 2024/12/13 01:23:12 INFO : sub dir: Set directory modification time (using DirSetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-nuguwer9fuxa'", Local "Local file system at /tmp/rclone588269293", Modify Window "1ms" 2024/12/13 01:23:12 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-luselom2bavo': Purge remote 2024/12/13 01:23:14 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestServerSideCopy (13.56s) === RUN TestCopyOverSelf run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-nuguwer9fuxa'", Local "Local file system at /tmp/rclone588269293", Modify Window "1ms" 2024/12/13 01:23:18 DEBUG : sub dir/hello world: md5 = 35baa7f5b8f974fce1b29211c9b05ad6 OK 2024/12/13 01:23:19 DEBUG : Added delayed dir = "sub dir", newDst=sub dir 2024/12/13 01:23:19 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-nuguwer9fuxa': Waiting for checks to finish 2024/12/13 01:23:19 DEBUG : sub dir/hello world: Sizes differ (src 17 vs dst 11) 2024/12/13 01:23:19 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-nuguwer9fuxa': Waiting for transfers to finish 2024/12/13 01:23:21 DEBUG : sub dir/hello world: md5 = 8528bfd4160e6e0e2df70b5dc7f5f53f OK 2024/12/13 01:23:21 INFO : sub dir/hello world: Copied (replaced existing) 2024/12/13 01:23:21 INFO : sub dir: Set directory modification time (using SetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-nuguwer9fuxa'", Local "Local file system at /tmp/rclone588269293", Modify Window "1ms" 2024/12/13 01:23:23 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestCopyOverSelf (8.96s) === RUN TestServerSideCopyOverSelf run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-nuguwer9fuxa'", Local "Local file system at /tmp/rclone588269293", Modify Window "1ms" 2024/12/13 01:23:27 DEBUG : sub dir/hello world: md5 = 17b3918a6ea07b522da8bca37113759d OK 2024/12/13 01:23:28 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-dipubiq3foye" 2024/12/13 01:23:28 DEBUG : Config file has changed externally - reloading 2024/12/13 01:23:28 DEBUG : Creating backend with remote "TestDrive:crypt/87fvh3dpmlp2g8l2iu8m25r90r5t43uoba6kh8vd670b852prbj0" sync_test.go:626: Server side copy (if possible) Encrypted drive 'TestCryptDrive:rclone-test-nuguwer9fuxa' -> Encrypted drive 'TestCryptDrive:rclone-test-dipubiq3foye' 2024/12/13 01:23:29 DEBUG : Added delayed dir = "sub dir", newDst= 2024/12/13 01:23:29 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2024/12/13 01:23:29 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dipubiq3foye': Waiting for checks to finish 2024/12/13 01:23:29 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dipubiq3foye': Waiting for transfers to finish 2024/12/13 01:23:33 INFO : sub dir/hello world: Copied (server-side copy) 2024/12/13 01:23:33 INFO : sub dir: Set directory modification time (using DirSetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-nuguwer9fuxa'", Local "Local file system at /tmp/rclone588269293", Modify Window "1ms" 2024/12/13 01:23:36 DEBUG : sub dir/hello world: md5 = b77cc9105136e5e320306aebaff7ce55 OK 2024/12/13 01:23:36 DEBUG : sub dir: Directory modification time the same (differ by 0s, within tolerance 1ms) 2024/12/13 01:23:36 DEBUG : Added delayed dir = "sub dir", newDst=sub dir 2024/12/13 01:23:37 DEBUG : sub dir/hello world: Sizes differ (src 17 vs dst 11) 2024/12/13 01:23:37 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dipubiq3foye': Waiting for checks to finish 2024/12/13 01:23:37 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dipubiq3foye': Waiting for transfers to finish 2024/12/13 01:23:39 INFO : sub dir/hello world: Copied (server-side copy) 2024/12/13 01:23:40 INFO : sub dir: Set directory modification time (using SetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-nuguwer9fuxa'", Local "Local file system at /tmp/rclone588269293", Modify Window "1ms" 2024/12/13 01:23:40 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dipubiq3foye': Purge remote 2024/12/13 01:23:42 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestServerSideCopyOverSelf (19.35s) === RUN TestMoveOverSelf run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-nuguwer9fuxa'", Local "Local file system at /tmp/rclone588269293", Modify Window "1ms" 2024/12/13 01:23:47 DEBUG : sub dir/hello world: md5 = c9ccf93fbc22b6ae03bc538e5e0e285b OK 2024/12/13 01:23:47 DEBUG : Added delayed dir = "sub dir", newDst=sub dir 2024/12/13 01:23:48 DEBUG : sub dir/hello world: Sizes differ (src 17 vs dst 11) 2024/12/13 01:23:48 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-nuguwer9fuxa': Waiting for checks to finish 2024/12/13 01:23:48 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-nuguwer9fuxa': Waiting for transfers to finish 2024/12/13 01:23:49 DEBUG : sub dir/hello world: md5 = e9ac4d0e9a7b0e883360b1aec08896f2 OK 2024/12/13 01:23:49 INFO : sub dir/hello world: Copied (replaced existing) 2024/12/13 01:23:49 INFO : sub dir/hello world: Deleted 2024/12/13 01:23:50 INFO : sub dir: Set directory modification time (using SetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-nuguwer9fuxa'", Local "Local file system at /tmp/rclone588269293", Modify Window "1ms" 2024/12/13 01:23:52 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestMoveOverSelf (8.99s) === RUN TestServerSideMoveOverSelf run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-nuguwer9fuxa'", Local "Local file system at /tmp/rclone588269293", Modify Window "1ms" 2024/12/13 01:23:56 DEBUG : sub dir/hello world: md5 = e9eaffc193405f5cda56806dfac44ce4 OK 2024/12/13 01:23:56 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-doqudaz2kabo" 2024/12/13 01:23:56 DEBUG : Creating backend with remote "TestDrive:crypt/4dj9sjtbpldcva7m95c4a18frcvt2dd486vnur0js3lb56kph300" sync_test.go:671: Server side copy (if possible) Encrypted drive 'TestCryptDrive:rclone-test-nuguwer9fuxa' -> Encrypted drive 'TestCryptDrive:rclone-test-doqudaz2kabo' 2024/12/13 01:23:58 DEBUG : Added delayed dir = "sub dir", newDst= 2024/12/13 01:23:58 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2024/12/13 01:23:58 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-doqudaz2kabo': Waiting for checks to finish 2024/12/13 01:23:58 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-doqudaz2kabo': Waiting for transfers to finish 2024/12/13 01:24:01 INFO : sub dir/hello world: Copied (server-side copy) 2024/12/13 01:24:02 INFO : sub dir: Set directory modification time (using DirSetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-nuguwer9fuxa'", Local "Local file system at /tmp/rclone588269293", Modify Window "1ms" 2024/12/13 01:24:04 DEBUG : sub dir/hello world: md5 = caf45ecb038a881167b989db2141a172 OK 2024/12/13 01:24:05 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-doqudaz2kabo': Using server-side directory move 2024/12/13 01:24:05 INFO : Encrypted drive 'TestCryptDrive:rclone-test-doqudaz2kabo': Server side directory move failed - fallback to file moves: can't copy directory - destination already exists 2024/12/13 01:24:05 DEBUG : sub dir: Directory modification time the same (differ by 0s, within tolerance 1ms) 2024/12/13 01:24:05 DEBUG : Added delayed dir = "sub dir", newDst=sub dir 2024/12/13 01:24:05 DEBUG : sub dir/hello world: Sizes differ (src 17 vs dst 11) 2024/12/13 01:24:05 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-doqudaz2kabo': Waiting for checks to finish 2024/12/13 01:24:05 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-doqudaz2kabo': Waiting for transfers to finish 2024/12/13 01:24:06 INFO : sub dir/hello world: Deleted 2024/12/13 01:24:07 INFO : sub dir/hello world: Moved (server-side) 2024/12/13 01:24:07 INFO : sub dir: Set directory modification time (using SetModTime) 2024/12/13 01:24:10 DEBUG : sub dir/hello world: md5 = a36e5be8585874a8e187f0fc8f297315 OK 2024/12/13 01:24:10 DEBUG : testing file moves 2024/12/13 01:24:11 DEBUG : sub dir: Directory modification time the same (differ by 0s, within tolerance 1ms) 2024/12/13 01:24:11 DEBUG : Added delayed dir = "sub dir", newDst=sub dir 2024/12/13 01:24:11 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-doqudaz2kabo': Waiting for checks to finish 2024/12/13 01:24:11 DEBUG : sub dir/hello world: Sizes differ (src 24 vs dst 17) 2024/12/13 01:24:11 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-doqudaz2kabo': Waiting for transfers to finish 2024/12/13 01:24:11 INFO : sub dir/hello world: Deleted 2024/12/13 01:24:12 INFO : sub dir/hello world: Moved (server-side) 2024/12/13 01:24:13 INFO : sub dir: Set directory modification time (using SetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-nuguwer9fuxa'", Local "Local file system at /tmp/rclone588269293", Modify Window "1ms" 2024/12/13 01:24:14 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-doqudaz2kabo': Purge remote --- PASS: TestServerSideMoveOverSelf (24.27s) === RUN TestCopyAfterDelete run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-nuguwer9fuxa'", Local "Local file system at /tmp/rclone588269293", Modify Window "1ms" 2024/12/13 01:24:20 DEBUG : sub dir/hello world: md5 = 65612c47f1df322a4d37200bb2430316 OK 2024/12/13 01:24:20 ERROR : : error listing: directory not found 2024/12/13 01:24:20 DEBUG : Local file system at /tmp/rclone588269293: Making directory 2024/12/13 01:24:21 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-nuguwer9fuxa': Waiting for checks to finish 2024/12/13 01:24:21 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-nuguwer9fuxa': Waiting for transfers to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-nuguwer9fuxa'", Local "Local file system at /tmp/rclone588269293", Modify Window "1ms" 2024/12/13 01:24:22 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestCopyAfterDelete (6.54s) === RUN TestCopyRedownload run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-nuguwer9fuxa'", Local "Local file system at /tmp/rclone588269293", Modify Window "1ms" 2024/12/13 01:24:27 DEBUG : sub dir/hello world: md5 = 8216910b935b0fd54fb928e757357de8 OK 2024/12/13 01:24:28 DEBUG : Added delayed dir = "sub dir", newDst= 2024/12/13 01:24:28 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2024/12/13 01:24:28 DEBUG : Local file system at /tmp/rclone588269293: Waiting for checks to finish 2024/12/13 01:24:28 DEBUG : Local file system at /tmp/rclone588269293: Waiting for transfers to finish 2024/12/13 01:24:29 DEBUG : sub dir/hello world.285f0a30.partial: renamed to: sub dir/hello world 2024/12/13 01:24:29 INFO : sub dir/hello world: Copied (new) 2024/12/13 01:24:29 INFO : sub dir: Set directory modification time (using DirSetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-nuguwer9fuxa'", Local "Local file system at /tmp/rclone588269293", Modify Window "1ms" 2024/12/13 01:24:30 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestCopyRedownload (8.13s) === RUN TestSyncBasedOnCheckSum run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-nuguwer9fuxa'", Local "Local file system at /tmp/rclone588269293", Modify Window "1ms" 2024/12/13 01:24:32 DEBUG : check sum: Need to transfer - File not found at Destination 2024/12/13 01:24:32 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-nuguwer9fuxa': Waiting for checks to finish 2024/12/13 01:24:32 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-nuguwer9fuxa': Waiting for transfers to finish 2024/12/13 01:24:34 DEBUG : check sum: md5 = 066f3d39453c274ca24c7eb401fd2ee6 OK 2024/12/13 01:24:34 INFO : check sum: Copied (new) 2024/12/13 01:24:34 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-nuguwer9fuxa'", Local "Local file system at /tmp/rclone588269293", Modify Window "1ms" 2024/12/13 01:24:34 NOTICE: Encrypted drive 'TestCryptDrive:rclone-test-nuguwer9fuxa': --checksum is in use but the source and destination have no hashes in common; falling back to --size-only 2024/12/13 01:24:34 DEBUG : check sum: Size of src and dst objects identical 2024/12/13 01:24:34 DEBUG : check sum: Unchanged skipping 2024/12/13 01:24:34 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-nuguwer9fuxa': Waiting for checks to finish 2024/12/13 01:24:34 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-nuguwer9fuxa': Waiting for transfers to finish 2024/12/13 01:24:34 DEBUG : Waiting for deletions to finish 2024/12/13 01:24:34 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-nuguwer9fuxa'", Local "Local file system at /tmp/rclone588269293", Modify Window "1ms" --- PASS: TestSyncBasedOnCheckSum (4.57s) === RUN TestSyncSizeOnly run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-nuguwer9fuxa'", Local "Local file system at /tmp/rclone588269293", Modify Window "1ms" 2024/12/13 01:24:37 DEBUG : sizeonly: Need to transfer - File not found at Destination 2024/12/13 01:24:37 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-nuguwer9fuxa': Waiting for checks to finish 2024/12/13 01:24:37 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-nuguwer9fuxa': Waiting for transfers to finish 2024/12/13 01:24:38 DEBUG : sizeonly: md5 = ab7b7aed92427c1aea0c49efcd01ca37 OK 2024/12/13 01:24:38 INFO : sizeonly: Copied (new) 2024/12/13 01:24:38 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-nuguwer9fuxa'", Local "Local file system at /tmp/rclone588269293", Modify Window "1ms" 2024/12/13 01:24:39 DEBUG : sizeonly: Sizes identical 2024/12/13 01:24:39 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-nuguwer9fuxa': Waiting for checks to finish 2024/12/13 01:24:39 DEBUG : sizeonly: Unchanged skipping 2024/12/13 01:24:39 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-nuguwer9fuxa': Waiting for transfers to finish 2024/12/13 01:24:39 DEBUG : Waiting for deletions to finish 2024/12/13 01:24:39 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-nuguwer9fuxa'", Local "Local file system at /tmp/rclone588269293", Modify Window "1ms" --- PASS: TestSyncSizeOnly (4.58s) === RUN TestSyncIgnoreSize run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-nuguwer9fuxa'", Local "Local file system at /tmp/rclone588269293", Modify Window "1ms" 2024/12/13 01:24:41 DEBUG : ignore-size: Need to transfer - File not found at Destination 2024/12/13 01:24:41 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-nuguwer9fuxa': Waiting for checks to finish 2024/12/13 01:24:41 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-nuguwer9fuxa': Waiting for transfers to finish 2024/12/13 01:24:43 DEBUG : ignore-size: md5 = e4b9c77e413269eced0b13f8f598c496 OK 2024/12/13 01:24:43 INFO : ignore-size: Copied (new) 2024/12/13 01:24:43 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-nuguwer9fuxa'", Local "Local file system at /tmp/rclone588269293", Modify Window "1ms" 2024/12/13 01:24:43 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-nuguwer9fuxa': Waiting for checks to finish 2024/12/13 01:24:43 DEBUG : ignore-size: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2024/12/13 01:24:43 DEBUG : ignore-size: Unchanged skipping 2024/12/13 01:24:43 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-nuguwer9fuxa': Waiting for transfers to finish 2024/12/13 01:24:43 DEBUG : Waiting for deletions to finish 2024/12/13 01:24:43 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-nuguwer9fuxa'", Local "Local file system at /tmp/rclone588269293", Modify Window "1ms" --- PASS: TestSyncIgnoreSize (4.58s) === RUN TestSyncIgnoreTimes run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-nuguwer9fuxa'", Local "Local file system at /tmp/rclone588269293", Modify Window "1ms" 2024/12/13 01:24:47 DEBUG : existing: md5 = 83d539868f2a5c7e156e027d18e27ca1 OK 2024/12/13 01:24:48 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-nuguwer9fuxa': Waiting for checks to finish 2024/12/13 01:24:48 DEBUG : existing: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2024/12/13 01:24:48 DEBUG : existing: Unchanged skipping 2024/12/13 01:24:48 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-nuguwer9fuxa': Waiting for transfers to finish 2024/12/13 01:24:48 DEBUG : Waiting for deletions to finish 2024/12/13 01:24:48 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-nuguwer9fuxa'", Local "Local file system at /tmp/rclone588269293", Modify Window "1ms" 2024/12/13 01:24:48 DEBUG : existing: Transferring unconditionally as --ignore-times is in use 2024/12/13 01:24:48 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-nuguwer9fuxa': Waiting for checks to finish 2024/12/13 01:24:48 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-nuguwer9fuxa': Waiting for transfers to finish 2024/12/13 01:24:50 DEBUG : existing: md5 = adb4d2360fca8d4acb165db12f8f3f57 OK 2024/12/13 01:24:50 INFO : existing: Copied (replaced existing) 2024/12/13 01:24:50 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-nuguwer9fuxa'", Local "Local file system at /tmp/rclone588269293", Modify Window "1ms" --- PASS: TestSyncIgnoreTimes (6.12s) === RUN TestSyncIgnoreExisting run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-nuguwer9fuxa'", Local "Local file system at /tmp/rclone588269293", Modify Window "1ms" 2024/12/13 01:24:52 DEBUG : existing: Need to transfer - File not found at Destination 2024/12/13 01:24:52 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-nuguwer9fuxa': Waiting for checks to finish 2024/12/13 01:24:52 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-nuguwer9fuxa': Waiting for transfers to finish 2024/12/13 01:24:54 DEBUG : existing: md5 = 742ad73d463834277a535e3efa5ceef2 OK 2024/12/13 01:24:54 INFO : existing: Copied (new) 2024/12/13 01:24:54 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-nuguwer9fuxa'", Local "Local file system at /tmp/rclone588269293", Modify Window "1ms" 2024/12/13 01:24:54 DEBUG : existing: Destination exists, skipping 2024/12/13 01:24:54 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-nuguwer9fuxa': Waiting for checks to finish 2024/12/13 01:24:54 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-nuguwer9fuxa': Waiting for transfers to finish 2024/12/13 01:24:54 DEBUG : Waiting for deletions to finish 2024/12/13 01:24:54 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-nuguwer9fuxa'", Local "Local file system at /tmp/rclone588269293", Modify Window "1ms" --- PASS: TestSyncIgnoreExisting (4.81s) === RUN TestSyncIgnoreErrors run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-nuguwer9fuxa'", Local "Local file system at /tmp/rclone588269293", Modify Window "1ms" 2024/12/13 01:24:59 DEBUG : b/potato: md5 = 938865e73f912d00f4e177832864557b OK 2024/12/13 01:25:02 DEBUG : c/non empty space: md5 = 4de1a0c54e64191fbff4a1bf53c3dc9e OK 2024/12/13 01:25:02 DEBUG : d: Making directory 2024/12/13 01:25:04 DEBUG : Added delayed dir = "a", newDst= 2024/12/13 01:25:04 DEBUG : Added delayed dir = "c", newDst=c 2024/12/13 01:25:04 DEBUG : a/potato2: Need to transfer - File not found at Destination 2024/12/13 01:25:04 DEBUG : c/non empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2024/12/13 01:25:04 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-nuguwer9fuxa': Waiting for checks to finish 2024/12/13 01:25:04 DEBUG : c/non empty space: Unchanged skipping 2024/12/13 01:25:04 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-nuguwer9fuxa': Waiting for transfers to finish 2024/12/13 01:25:07 DEBUG : a/potato2: md5 = f48472c980995625234963e343be278a OK 2024/12/13 01:25:07 INFO : a/potato2: Copied (new) 2024/12/13 01:25:07 DEBUG : Waiting for deletions to finish 2024/12/13 01:25:08 INFO : b/potato: Deleted 2024/12/13 01:25:08 INFO : a: Set directory modification time (using DirSetModTime) 2024/12/13 01:25:08 INFO : d: Removing directory 2024/12/13 01:25:09 INFO : b: Removing directory 2024/12/13 01:25:09 DEBUG : 32d8ua6196mc1r7qkfog53rkg0: Rmdir: contains trashed file: "2m507n64kafsi59v9q71r281a4" 2024/12/13 01:25:10 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-nuguwer9fuxa': deleted 2 directories run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-nuguwer9fuxa'", Local "Local file system at /tmp/rclone588269293", Modify Window "1ms" 2024/12/13 01:25:12 DEBUG : 3i9du405pfogq3ncai6pg7ouio: Rmdir: contains trashed file: "982d3pss7t5pn0il16r2foj31s" 2024/12/13 01:25:13 DEBUG : 2bsvlrk2ne1lfitm6tttcu0qt8: Rmdir: contains trashed file: "89l8renevh3mji1c8r1p7qn6tg" --- PASS: TestSyncIgnoreErrors (18.10s) === RUN TestSyncAfterChangingModtimeOnly run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-nuguwer9fuxa'", Local "Local file system at /tmp/rclone588269293", Modify Window "1ms" 2024/12/13 01:25:16 DEBUG : empty space: md5 = b5bfc9bd55fb4981a523550ad0a738d6 OK 2024/12/13 01:25:17 DEBUG : empty space: Modification times differ by -95456h54m52.624456789s: 2011-12-25 12:59:59.123456789 +0000 UTC, 2001-02-03 04:05:06.499 +0000 UTC 2024/12/13 01:25:17 NOTICE: empty space: Skipped copy as --dry-run is set (size 1) 2024/12/13 01:25:17 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-nuguwer9fuxa': Waiting for checks to finish 2024/12/13 01:25:17 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-nuguwer9fuxa': Waiting for transfers to finish 2024/12/13 01:25:17 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-nuguwer9fuxa'", Local "Local file system at /tmp/rclone588269293", Modify Window "1ms" 2024/12/13 01:25:17 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-nuguwer9fuxa': Waiting for checks to finish 2024/12/13 01:25:17 DEBUG : empty space: Modification times differ by -95456h54m52.624456789s: 2011-12-25 12:59:59.123456789 +0000 UTC, 2001-02-03 04:05:06.499 +0000 UTC 2024/12/13 01:25:17 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-nuguwer9fuxa': Waiting for transfers to finish 2024/12/13 01:25:18 DEBUG : empty space: md5 = 8219cd9db8bff21f75cd868f082408f3 OK 2024/12/13 01:25:18 INFO : empty space: Copied (replaced existing) 2024/12/13 01:25:18 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-nuguwer9fuxa'", Local "Local file system at /tmp/rclone588269293", Modify Window "1ms" --- PASS: TestSyncAfterChangingModtimeOnly (6.06s) === RUN TestSyncAfterChangingModtimeOnlyWithNoUpdateModTime run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-nuguwer9fuxa'", Local "Local file system at /tmp/rclone588269293", Modify Window "1ms" sync_test.go:1016: Can't check this if no hashes supported --- PASS: TestSyncAfterChangingModtimeOnlyWithNoUpdateModTime (0.49s) === RUN TestSyncDoesntUpdateModtime run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-nuguwer9fuxa'", Local "Local file system at /tmp/rclone588269293", Modify Window "1ms" 2024/12/13 01:25:23 DEBUG : foo: md5 = 5c9149e0c1b80dc5298f3d48021994c7 OK 2024/12/13 01:25:23 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-nuguwer9fuxa': Waiting for checks to finish 2024/12/13 01:25:23 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/13 01:25:23 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-nuguwer9fuxa': Waiting for transfers to finish 2024/12/13 01:25:25 DEBUG : foo: md5 = db5301e1a25b17320d3ce1060520f44a OK 2024/12/13 01:25:25 INFO : foo: Copied (replaced existing) 2024/12/13 01:25:25 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-nuguwer9fuxa'", Local "Local file system at /tmp/rclone588269293", Modify Window "1ms" --- PASS: TestSyncDoesntUpdateModtime (5.23s) === RUN TestSyncAfterAddingAFile run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-nuguwer9fuxa'", Local "Local file system at /tmp/rclone588269293", Modify Window "1ms" 2024/12/13 01:25:28 DEBUG : empty space: md5 = f023504a3c372335a5facbf25405c0d6 OK 2024/12/13 01:25:29 DEBUG : potato: Need to transfer - File not found at Destination 2024/12/13 01:25:29 DEBUG : empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2024/12/13 01:25:29 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-nuguwer9fuxa': Waiting for checks to finish 2024/12/13 01:25:29 DEBUG : empty space: Unchanged skipping 2024/12/13 01:25:29 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-nuguwer9fuxa': Waiting for transfers to finish 2024/12/13 01:25:30 DEBUG : potato: md5 = 9b620b81ca071b36245312181546d41f OK 2024/12/13 01:25:30 INFO : potato: Copied (new) 2024/12/13 01:25:30 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-nuguwer9fuxa'", Local "Local file system at /tmp/rclone588269293", Modify Window "1ms" --- PASS: TestSyncAfterAddingAFile (6.49s) === RUN TestSyncAfterChangingFilesSizeOnly run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-nuguwer9fuxa'", Local "Local file system at /tmp/rclone588269293", Modify Window "1ms" 2024/12/13 01:25:35 DEBUG : potato: md5 = f45e600f7921e20a6dc3ab9c3a16c654 OK 2024/12/13 01:25:35 DEBUG : potato: Sizes differ (src 21 vs dst 60) 2024/12/13 01:25:35 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-nuguwer9fuxa': Waiting for checks to finish 2024/12/13 01:25:35 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-nuguwer9fuxa': Waiting for transfers to finish 2024/12/13 01:25:37 DEBUG : potato: md5 = 3178f9d04463da9b685eb8bf33621603 OK 2024/12/13 01:25:37 INFO : potato: Copied (replaced existing) 2024/12/13 01:25:37 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-nuguwer9fuxa'", Local "Local file system at /tmp/rclone588269293", Modify Window "1ms" --- PASS: TestSyncAfterChangingFilesSizeOnly (5.45s) === RUN TestSyncAfterChangingContentsOnly run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-nuguwer9fuxa'", Local "Local file system at /tmp/rclone588269293", Modify Window "1ms" 2024/12/13 01:25:40 DEBUG : potato: md5 = 11139a19f55247bafa7922b7e000cfc8 OK 2024/12/13 01:25:40 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/13 01:25:40 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-nuguwer9fuxa': Waiting for checks to finish 2024/12/13 01:25:40 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-nuguwer9fuxa': Waiting for transfers to finish 2024/12/13 01:25:42 DEBUG : potato: md5 = 977cee1a6116863fa48f81cf8254c036 OK 2024/12/13 01:25:42 INFO : potato: Copied (replaced existing) 2024/12/13 01:25:42 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-nuguwer9fuxa'", Local "Local file system at /tmp/rclone588269293", Modify Window "1ms" --- PASS: TestSyncAfterChangingContentsOnly (5.14s) === RUN TestSyncAfterRemovingAFileAndAddingAFileDryRun run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-nuguwer9fuxa'", Local "Local file system at /tmp/rclone588269293", Modify Window "1ms" 2024/12/13 01:25:45 DEBUG : potato: md5 = 41aa72d9268276b5e27754ea1080d13f OK 2024/12/13 01:25:47 DEBUG : empty space: md5 = 5bb10cf2b5f7fc8fd1c263e15b537c39 OK 2024/12/13 01:25:47 DEBUG : potato2: Need to transfer - File not found at Destination 2024/12/13 01:25:47 NOTICE: potato2: Skipped copy as --dry-run is set (size 60) 2024/12/13 01:25:47 DEBUG : empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2024/12/13 01:25:47 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-nuguwer9fuxa': Waiting for checks to finish 2024/12/13 01:25:47 DEBUG : empty space: Unchanged skipping 2024/12/13 01:25:47 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-nuguwer9fuxa': Waiting for transfers to finish 2024/12/13 01:25:47 DEBUG : Waiting for deletions to finish 2024/12/13 01:25:47 NOTICE: potato: Skipped delete as --dry-run is set (size 21) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-nuguwer9fuxa'", Local "Local file system at /tmp/rclone588269293", Modify Window "1ms" --- PASS: TestSyncAfterRemovingAFileAndAddingAFileDryRun (6.24s) === RUN TestSyncAfterRemovingAFileAndAddingAFile run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-nuguwer9fuxa'", Local "Local file system at /tmp/rclone588269293", Modify Window "1ms" 2024/12/13 01:25:51 DEBUG : potato: md5 = b740513d1460d5050940601247346f11 OK 2024/12/13 01:25:53 DEBUG : empty space: md5 = f9aa83003a6b17ebeffdb6d9b00e4113 OK 2024/12/13 01:25:54 DEBUG : potato2: Need to transfer - File not found at Destination 2024/12/13 01:25:54 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-nuguwer9fuxa': Waiting for checks to finish 2024/12/13 01:25:54 DEBUG : empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2024/12/13 01:25:54 DEBUG : empty space: Unchanged skipping 2024/12/13 01:25:54 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-nuguwer9fuxa': Waiting for transfers to finish 2024/12/13 01:25:56 DEBUG : potato2: md5 = 5036d284c84b0bf8b41f96993d435352 OK 2024/12/13 01:25:56 INFO : potato2: Copied (new) 2024/12/13 01:25:56 DEBUG : Waiting for deletions to finish 2024/12/13 01:25:56 INFO : potato: Deleted run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-nuguwer9fuxa'", Local "Local file system at /tmp/rclone588269293", Modify Window "1ms" --- PASS: TestSyncAfterRemovingAFileAndAddingAFile (8.79s) === RUN TestSyncAfterRemovingAFileAndAddingAFileSubDir run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-nuguwer9fuxa'", Local "Local file system at /tmp/rclone588269293", Modify Window "1ms" 2024/12/13 01:26:01 DEBUG : b/potato: md5 = af1b0b4a9552256e1442bff5e2616cdb OK 2024/12/13 01:26:04 DEBUG : c/non empty space: md5 = 24c6f4edc05a521d770071a51aa38f44 OK 2024/12/13 01:26:04 DEBUG : d: Making directory 2024/12/13 01:26:05 DEBUG : d/e: Making directory 2024/12/13 01:26:07 DEBUG : Added delayed dir = "a", newDst= 2024/12/13 01:26:07 DEBUG : Added delayed dir = "c", newDst=c 2024/12/13 01:26:07 DEBUG : a/potato2: Need to transfer - File not found at Destination 2024/12/13 01:26:07 DEBUG : c/non empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2024/12/13 01:26:07 DEBUG : c/non empty space: Unchanged skipping 2024/12/13 01:26:09 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-nuguwer9fuxa': Waiting for checks to finish 2024/12/13 01:26:09 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-nuguwer9fuxa': Waiting for transfers to finish 2024/12/13 01:26:10 DEBUG : a/potato2: md5 = 4460c42f1d5cb448dda73644355539bf OK 2024/12/13 01:26:10 INFO : a/potato2: Copied (new) 2024/12/13 01:26:10 DEBUG : Waiting for deletions to finish 2024/12/13 01:26:10 INFO : b/potato: Deleted 2024/12/13 01:26:11 INFO : a: Set directory modification time (using DirSetModTime) 2024/12/13 01:26:11 INFO : d/e: Removing directory 2024/12/13 01:26:12 INFO : d: Removing directory 2024/12/13 01:26:12 DEBUG : ka6id8d20d3s5ktapedlphgta8: Rmdir: contains trashed file: "r8sppajuabeak3sbgj2ak8vuf8" 2024/12/13 01:26:13 INFO : b: Removing directory 2024/12/13 01:26:13 DEBUG : 32d8ua6196mc1r7qkfog53rkg0: Rmdir: contains trashed file: "2m507n64kafsi59v9q71r281a4" 2024/12/13 01:26:14 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-nuguwer9fuxa': deleted 3 directories run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-nuguwer9fuxa'", Local "Local file system at /tmp/rclone588269293", Modify Window "1ms" 2024/12/13 01:26:16 DEBUG : 3i9du405pfogq3ncai6pg7ouio: Rmdir: contains trashed file: "982d3pss7t5pn0il16r2foj31s" 2024/12/13 01:26:17 DEBUG : 2bsvlrk2ne1lfitm6tttcu0qt8: Rmdir: contains trashed file: "89l8renevh3mji1c8r1p7qn6tg" --- PASS: TestSyncAfterRemovingAFileAndAddingAFileSubDir (19.68s) === RUN TestSyncAfterRemovingAFileAndAddingAFileSubDirWithErrors run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-nuguwer9fuxa'", Local "Local file system at /tmp/rclone588269293", Modify Window "1ms" 2024/12/13 01:26:21 DEBUG : b/potato: md5 = bf60131f095794aa4daf39b9a9b145d9 OK 2024/12/13 01:26:24 DEBUG : c/non empty space: md5 = 61c8c795616d5ae9db8ce4ccf2f15808 OK 2024/12/13 01:26:24 DEBUG : d: Making directory 2024/12/13 01:26:26 DEBUG : Added delayed dir = "a", newDst= 2024/12/13 01:26:26 DEBUG : Added delayed dir = "c", newDst=c 2024/12/13 01:26:26 DEBUG : a/potato2: Need to transfer - File not found at Destination 2024/12/13 01:26:26 DEBUG : c/non empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2024/12/13 01:26:26 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-nuguwer9fuxa': Waiting for checks to finish 2024/12/13 01:26:26 DEBUG : c/non empty space: Unchanged skipping 2024/12/13 01:26:26 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-nuguwer9fuxa': Waiting for transfers to finish 2024/12/13 01:26:29 DEBUG : a/potato2: md5 = f87b4d85dc96d6dd9e88b8f57d37c825 OK 2024/12/13 01:26:29 INFO : a/potato2: Copied (new) 2024/12/13 01:26:29 ERROR : Encrypted drive 'TestCryptDrive:rclone-test-nuguwer9fuxa': not deleting files as there were IO errors 2024/12/13 01:26:29 INFO : a: Set directory modification time (using DirSetModTime) 2024/12/13 01:26:29 ERROR : Encrypted drive 'TestCryptDrive:rclone-test-nuguwer9fuxa': not deleting directories as there were IO errors run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-nuguwer9fuxa'", Local "Local file system at /tmp/rclone588269293", Modify Window "1ms" 2024/12/13 01:26:33 DEBUG : 3i9du405pfogq3ncai6pg7ouio: Rmdir: contains trashed file: "982d3pss7t5pn0il16r2foj31s" 2024/12/13 01:26:34 DEBUG : 32d8ua6196mc1r7qkfog53rkg0: Rmdir: contains trashed file: "2m507n64kafsi59v9q71r281a4" 2024/12/13 01:26:35 DEBUG : 2bsvlrk2ne1lfitm6tttcu0qt8: Rmdir: contains trashed file: "89l8renevh3mji1c8r1p7qn6tg" --- PASS: TestSyncAfterRemovingAFileAndAddingAFileSubDirWithErrors (17.88s) === RUN TestSyncDeleteAfter --- PASS: TestSyncDeleteAfter (0.00s) === RUN TestSyncDeleteDuring run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-nuguwer9fuxa'", Local "Local file system at /tmp/rclone588269293", Modify Window "1ms" 2024/12/13 01:26:38 DEBUG : potato: md5 = 955c758b569f5a8309ed9506416ecc3f OK 2024/12/13 01:26:39 DEBUG : empty space: md5 = 6d3bf855668970db22d87d51100a9d1b OK 2024/12/13 01:26:40 DEBUG : Waiting for deletions to finish 2024/12/13 01:26:40 DEBUG : potato2: Need to transfer - File not found at Destination 2024/12/13 01:26:40 DEBUG : empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2024/12/13 01:26:40 DEBUG : empty space: Unchanged skipping 2024/12/13 01:26:40 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-nuguwer9fuxa': Waiting for checks to finish 2024/12/13 01:26:40 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-nuguwer9fuxa': Waiting for transfers to finish 2024/12/13 01:26:40 INFO : potato: Deleted 2024/12/13 01:26:41 DEBUG : potato2: md5 = 03a9e45ab7055a5369a9663544ccc96a OK 2024/12/13 01:26:41 INFO : potato2: Copied (new) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-nuguwer9fuxa'", Local "Local file system at /tmp/rclone588269293", Modify Window "1ms" --- PASS: TestSyncDeleteDuring (8.39s) === RUN TestSyncDeleteBefore run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-nuguwer9fuxa'", Local "Local file system at /tmp/rclone588269293", Modify Window "1ms" 2024/12/13 01:26:46 DEBUG : potato: md5 = 58be7ec543d3d9a44b127495b4a1b2cd OK 2024/12/13 01:26:48 DEBUG : empty space: md5 = d6e6a1d558a9cdef34c3bcc52e6d7f4a OK 2024/12/13 01:26:48 DEBUG : Waiting for deletions to finish 2024/12/13 01:26:48 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-nuguwer9fuxa': Waiting for checks to finish 2024/12/13 01:26:48 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-nuguwer9fuxa': Waiting for transfers to finish 2024/12/13 01:26:49 INFO : potato: Deleted 2024/12/13 01:26:49 DEBUG : potato2: Need to transfer - File not found at Destination 2024/12/13 01:26:49 DEBUG : empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2024/12/13 01:26:49 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-nuguwer9fuxa': Waiting for checks to finish 2024/12/13 01:26:49 DEBUG : empty space: Unchanged skipping 2024/12/13 01:26:49 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-nuguwer9fuxa': Waiting for transfers to finish 2024/12/13 01:26:51 DEBUG : potato2: md5 = 0d6ce63214b8669c2d3c129856c7e387 OK 2024/12/13 01:26:51 INFO : potato2: Copied (new) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-nuguwer9fuxa'", Local "Local file system at /tmp/rclone588269293", Modify Window "1ms" --- PASS: TestSyncDeleteBefore (8.76s) === RUN TestCopyDeleteBefore run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-nuguwer9fuxa'", Local "Local file system at /tmp/rclone588269293", Modify Window "1ms" 2024/12/13 01:26:55 DEBUG : potato: md5 = c85dc1da52f15cd3d504e7e8449e5dc5 OK 2024/12/13 01:26:56 DEBUG : potato2: Need to transfer - File not found at Destination 2024/12/13 01:26:56 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-nuguwer9fuxa': Waiting for checks to finish 2024/12/13 01:26:56 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-nuguwer9fuxa': Waiting for transfers to finish 2024/12/13 01:26:57 DEBUG : potato2: md5 = 85bc55dec746303b157fb37289237979 OK 2024/12/13 01:26:57 INFO : potato2: Copied (new) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-nuguwer9fuxa'", Local "Local file system at /tmp/rclone588269293", Modify Window "1ms" --- PASS: TestCopyDeleteBefore (6.30s) === RUN TestSyncWithExclude run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-nuguwer9fuxa'", Local "Local file system at /tmp/rclone588269293", Modify Window "1ms" 2024/12/13 01:27:01 DEBUG : potato2: md5 = e08ec0af01be112e38cab8290fff7c1a OK 2024/12/13 01:27:03 DEBUG : empty space: md5 = a52363bff1c49dc43e2b49a813f009b1 OK 2024/12/13 01:27:03 DEBUG : enormous: Excluded (Size Filter) 2024/12/13 01:27:03 DEBUG : enormous: Excluded 2024/12/13 01:27:03 DEBUG : potato2: Excluded (Size Filter) 2024/12/13 01:27:03 DEBUG : potato2: Excluded 2024/12/13 01:27:03 DEBUG : potato2: Excluded (Size Filter) 2024/12/13 01:27:03 DEBUG : potato2: Excluded 2024/12/13 01:27:03 DEBUG : empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2024/12/13 01:27:03 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-nuguwer9fuxa': Waiting for checks to finish 2024/12/13 01:27:03 DEBUG : empty space: Unchanged skipping 2024/12/13 01:27:03 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-nuguwer9fuxa': Waiting for transfers to finish 2024/12/13 01:27:03 DEBUG : Waiting for deletions to finish 2024/12/13 01:27:03 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-nuguwer9fuxa'", Local "Local file system at /tmp/rclone588269293", Modify Window "1ms" 2024/12/13 01:27:03 DEBUG : enormous: Excluded (Size Filter) 2024/12/13 01:27:03 DEBUG : enormous: Excluded 2024/12/13 01:27:03 DEBUG : potato2: Excluded (Size Filter) 2024/12/13 01:27:03 DEBUG : potato2: Excluded 2024/12/13 01:27:04 DEBUG : potato2: Excluded (Size Filter) 2024/12/13 01:27:04 DEBUG : potato2: Excluded 2024/12/13 01:27:04 DEBUG : Local file system at /tmp/rclone588269293: Waiting for checks to finish 2024/12/13 01:27:04 DEBUG : empty space: Size and modification time the same (differ by 456.789µs, within tolerance 1ms) 2024/12/13 01:27:04 DEBUG : empty space: Unchanged skipping 2024/12/13 01:27:04 DEBUG : Local file system at /tmp/rclone588269293: Waiting for transfers to finish 2024/12/13 01:27:04 DEBUG : Waiting for deletions to finish 2024/12/13 01:27:04 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-nuguwer9fuxa'", Local "Local file system at /tmp/rclone588269293", Modify Window "1ms" --- PASS: TestSyncWithExclude (6.71s) === RUN TestSyncWithExcludeAndDeleteExcluded run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-nuguwer9fuxa'", Local "Local file system at /tmp/rclone588269293", Modify Window "1ms" 2024/12/13 01:27:08 DEBUG : potato2: md5 = 0eacdb68b28c9acd22f84b0b74c43a91 OK 2024/12/13 01:27:09 DEBUG : empty space: md5 = 329b121ef0f44ae66cfd87e80665df33 OK 2024/12/13 01:27:11 DEBUG : enormous: md5 = 56be370a1cb8e65011abc5ddb569b447 OK 2024/12/13 01:27:11 DEBUG : enormous: Excluded (Size Filter) 2024/12/13 01:27:11 DEBUG : enormous: Excluded 2024/12/13 01:27:11 DEBUG : potato2: Excluded (Size Filter) 2024/12/13 01:27:11 DEBUG : potato2: Excluded 2024/12/13 01:27:12 DEBUG : empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2024/12/13 01:27:12 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-nuguwer9fuxa': Waiting for checks to finish 2024/12/13 01:27:12 DEBUG : empty space: Unchanged skipping 2024/12/13 01:27:12 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-nuguwer9fuxa': Waiting for transfers to finish 2024/12/13 01:27:12 DEBUG : Waiting for deletions to finish 2024/12/13 01:27:12 INFO : potato2: Deleted 2024/12/13 01:27:12 INFO : enormous: Deleted 2024/12/13 01:27:12 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-nuguwer9fuxa'", Local "Local file system at /tmp/rclone588269293", Modify Window "1ms" 2024/12/13 01:27:13 DEBUG : Local file system at /tmp/rclone588269293: Waiting for checks to finish 2024/12/13 01:27:13 DEBUG : empty space: Size and modification time the same (differ by 456.789µs, within tolerance 1ms) 2024/12/13 01:27:13 DEBUG : empty space: Unchanged skipping 2024/12/13 01:27:13 DEBUG : Local file system at /tmp/rclone588269293: Waiting for transfers to finish 2024/12/13 01:27:13 DEBUG : Waiting for deletions to finish 2024/12/13 01:27:13 INFO : enormous: Deleted 2024/12/13 01:27:13 INFO : potato2: Deleted 2024/12/13 01:27:13 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-nuguwer9fuxa'", Local "Local file system at /tmp/rclone588269293", Modify Window "1ms" --- PASS: TestSyncWithExcludeAndDeleteExcluded (8.37s) === RUN TestSyncWithUpdateOlder run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-nuguwer9fuxa'", Local "Local file system at /tmp/rclone588269293", Modify Window "1ms" 2024/12/13 01:27:16 DEBUG : one: md5 = 3a9d33513f69a313b5fea9670fe176dc OK 2024/12/13 01:27:18 DEBUG : two: md5 = ac19f33fb3796802c37ef5bd115979a1 OK 2024/12/13 01:27:19 DEBUG : three: md5 = 6fc5a3689b34bc313caa8e19549aa0ce OK 2024/12/13 01:27:21 DEBUG : four: md5 = f2b72d3bf05d6c0b90ee76f932f1cda2 OK 2024/12/13 01:27:22 DEBUG : five: Need to transfer - File not found at Destination 2024/12/13 01:27:22 DEBUG : four: Sizes differ (src 4 vs dst 8) 2024/12/13 01:27:22 DEBUG : one: Destination is newer than source, skipping 2024/12/13 01:27:22 DEBUG : three: Sizes identical 2024/12/13 01:27:22 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-nuguwer9fuxa': Waiting for checks to finish 2024/12/13 01:27:22 DEBUG : four: Destination mod time is within 1s of source but files differ, transferring 2024/12/13 01:27:22 DEBUG : three: Destination mod time is within 1s of source and files identical, skipping 2024/12/13 01:27:22 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-nuguwer9fuxa': Waiting for transfers to finish 2024/12/13 01:27:23 DEBUG : two: md5 = b06a0dcb874423796b0691f626765857 OK 2024/12/13 01:27:23 INFO : two: Copied (replaced existing) 2024/12/13 01:27:23 DEBUG : four: md5 = 9feae8eaf7b7a39edd7826001473f05e OK 2024/12/13 01:27:23 INFO : four: Copied (replaced existing) 2024/12/13 01:27:23 DEBUG : five: md5 = 11f9671b29dda06888a3dcc607ef09d1 OK 2024/12/13 01:27:23 INFO : five: Copied (new) 2024/12/13 01:27:23 DEBUG : Waiting for deletions to finish sync_test.go:1449: Skip test with --checksum as no hashes supported --- PASS: TestSyncWithUpdateOlder (12.69s) === 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-nuguwer9fuxa'", Local "Local file system at /tmp/rclone588269293", Modify Window "1ms" sync_test.go:1538: Can track renames: false 2024/12/13 01:27:27 ERROR : Encrypted drive 'TestCryptDrive:rclone-test-nuguwer9fuxa': Ignoring --track-renames as the source and destination do not have a common hash 2024/12/13 01:27:27 DEBUG : potato: Need to transfer - File not found at Destination 2024/12/13 01:27:27 DEBUG : yam: Need to transfer - File not found at Destination 2024/12/13 01:27:27 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-nuguwer9fuxa': Waiting for checks to finish 2024/12/13 01:27:27 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-nuguwer9fuxa': Waiting for transfers to finish 2024/12/13 01:27:29 DEBUG : potato: md5 = 8ce2ebd9aa0f94e66ad69131312a6dc0 OK 2024/12/13 01:27:29 INFO : potato: Copied (new) 2024/12/13 01:27:29 DEBUG : yam: md5 = 7f6cc6079850f2409375ed0c3261d321 OK 2024/12/13 01:27:29 INFO : yam: Copied (new) 2024/12/13 01:27:29 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-nuguwer9fuxa'", Local "Local file system at /tmp/rclone588269293", Modify Window "1ms" 2024/12/13 01:27:29 ERROR : Encrypted drive 'TestCryptDrive:rclone-test-nuguwer9fuxa': Ignoring --track-renames as the source and destination do not have a common hash 2024/12/13 01:27:30 DEBUG : yaml: Need to transfer - File not found at Destination 2024/12/13 01:27:30 DEBUG : potato: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2024/12/13 01:27:30 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-nuguwer9fuxa': Waiting for checks to finish 2024/12/13 01:27:30 DEBUG : potato: Unchanged skipping 2024/12/13 01:27:30 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-nuguwer9fuxa': Waiting for transfers to finish 2024/12/13 01:27:31 DEBUG : yaml: md5 = 8867b7fe7778aa2ff5f619d1595151e0 OK 2024/12/13 01:27:31 INFO : yaml: Copied (new) 2024/12/13 01:27:31 DEBUG : Waiting for deletions to finish 2024/12/13 01:27:32 INFO : yam: Deleted run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-nuguwer9fuxa'", Local "Local file system at /tmp/rclone588269293", Modify Window "1ms" --- PASS: TestSyncWithTrackRenames (8.13s) === RUN TestParseRenamesStrategyModtime --- PASS: TestParseRenamesStrategyModtime (0.00s) === RUN TestRenamesStrategyModtime --- PASS: TestRenamesStrategyModtime (0.00s) === RUN TestSyncWithTrackRenamesStrategyModtime run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-nuguwer9fuxa'", Local "Local file system at /tmp/rclone588269293", Modify Window "1ms" sync_test.go:1610: Can track renames: true 2024/12/13 01:27:36 INFO : Encrypted drive 'TestCryptDrive:rclone-test-nuguwer9fuxa': Making map for --track-renames 2024/12/13 01:27:36 INFO : Encrypted drive 'TestCryptDrive:rclone-test-nuguwer9fuxa': Finished making map for --track-renames 2024/12/13 01:27:36 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-nuguwer9fuxa': Waiting for checks to finish 2024/12/13 01:27:36 DEBUG : potato: Need to transfer - No matching file found at Destination 2024/12/13 01:27:36 DEBUG : yam: Need to transfer - No matching file found at Destination 2024/12/13 01:27:36 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-nuguwer9fuxa': Waiting for renames to finish 2024/12/13 01:27:36 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-nuguwer9fuxa': Waiting for transfers to finish 2024/12/13 01:27:37 DEBUG : potato: md5 = 6e01bd87f4eb8f00db999e548dba0979 OK 2024/12/13 01:27:37 INFO : potato: Copied (new) 2024/12/13 01:27:37 DEBUG : yam: md5 = bb4bb4f5383cf4f3daf14880ff0b7a7c OK 2024/12/13 01:27:37 INFO : yam: Copied (new) 2024/12/13 01:27:37 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-nuguwer9fuxa'", Local "Local file system at /tmp/rclone588269293", Modify Window "1ms" 2024/12/13 01:27:38 DEBUG : potato: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2024/12/13 01:27:38 INFO : Encrypted drive 'TestCryptDrive:rclone-test-nuguwer9fuxa': Making map for --track-renames 2024/12/13 01:27:38 INFO : Encrypted drive 'TestCryptDrive:rclone-test-nuguwer9fuxa': Finished making map for --track-renames 2024/12/13 01:27:38 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-nuguwer9fuxa': Waiting for checks to finish 2024/12/13 01:27:38 DEBUG : potato: Unchanged skipping 2024/12/13 01:27:38 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-nuguwer9fuxa': Waiting for renames to finish 2024/12/13 01:27:39 INFO : yam: Moved (server-side) to: yaml 2024/12/13 01:27:39 INFO : yaml: Renamed from "yam" 2024/12/13 01:27:39 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-nuguwer9fuxa': Waiting for transfers to finish 2024/12/13 01:27:39 DEBUG : Waiting for deletions to finish 2024/12/13 01:27:39 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-nuguwer9fuxa'", Local "Local file system at /tmp/rclone588269293", Modify Window "1ms" --- PASS: TestSyncWithTrackRenamesStrategyModtime (6.26s) === RUN TestSyncWithTrackRenamesStrategyLeaf run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-nuguwer9fuxa'", Local "Local file system at /tmp/rclone588269293", Modify Window "1ms" sync_test.go:1649: Can track renames: true 2024/12/13 01:27:42 DEBUG : Added delayed dir = "sub", newDst= 2024/12/13 01:27:42 INFO : Encrypted drive 'TestCryptDrive:rclone-test-nuguwer9fuxa': Making map for --track-renames 2024/12/13 01:27:42 INFO : Encrypted drive 'TestCryptDrive:rclone-test-nuguwer9fuxa': Finished making map for --track-renames 2024/12/13 01:27:42 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-nuguwer9fuxa': Waiting for checks to finish 2024/12/13 01:27:42 DEBUG : potato: Need to transfer - No matching file found at Destination 2024/12/13 01:27:42 DEBUG : sub/yam: Need to transfer - No matching file found at Destination 2024/12/13 01:27:42 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-nuguwer9fuxa': Waiting for renames to finish 2024/12/13 01:27:42 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-nuguwer9fuxa': Waiting for transfers to finish 2024/12/13 01:27:45 DEBUG : sub/yam: md5 = 14c894dfd619ec04a75cdcb3b481e84e OK 2024/12/13 01:27:45 INFO : sub/yam: Copied (new) 2024/12/13 01:27:45 DEBUG : potato: md5 = d699bca6ac52aa5141d75731b4393645 OK 2024/12/13 01:27:45 INFO : potato: Copied (new) 2024/12/13 01:27:45 DEBUG : Waiting for deletions to finish 2024/12/13 01:27:46 INFO : sub: Set directory modification time (using DirSetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-nuguwer9fuxa'", Local "Local file system at /tmp/rclone588269293", Modify Window "1ms" 2024/12/13 01:27:47 DEBUG : Added delayed dir = "sub", newDst=sub 2024/12/13 01:27:47 DEBUG : potato: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2024/12/13 01:27:47 DEBUG : potato: Unchanged skipping 2024/12/13 01:27:47 INFO : Encrypted drive 'TestCryptDrive:rclone-test-nuguwer9fuxa': Making map for --track-renames 2024/12/13 01:27:47 INFO : Encrypted drive 'TestCryptDrive:rclone-test-nuguwer9fuxa': Finished making map for --track-renames 2024/12/13 01:27:47 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-nuguwer9fuxa': Waiting for checks to finish 2024/12/13 01:27:47 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-nuguwer9fuxa': Waiting for renames to finish 2024/12/13 01:27:48 INFO : sub/yam: Moved (server-side) to: yam 2024/12/13 01:27:48 INFO : yam: Renamed from "sub/yam" 2024/12/13 01:27:48 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-nuguwer9fuxa': Waiting for transfers to finish 2024/12/13 01:27:48 DEBUG : Waiting for deletions to finish 2024/12/13 01:27:48 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-nuguwer9fuxa'", Local "Local file system at /tmp/rclone588269293", Modify Window "1ms" --- PASS: TestSyncWithTrackRenamesStrategyLeaf (10.79s) === RUN TestServerSideMoveLocal run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-nuguwer9fuxa'", Local "Local file system at /tmp/rclone588269293", Modify Window "1ms" 2024/12/13 01:27:52 DEBUG : Creating backend with remote "/tmp/rclone588269293/dir1" 2024/12/13 01:27:52 DEBUG : Config file has changed externally - reloading 2024/12/13 01:27:52 DEBUG : Creating backend with remote "/tmp/rclone588269293/dir2" 2024/12/13 01:27:52 DEBUG : Local file system at /tmp/rclone588269293/dir2: Using server-side directory move 2024/12/13 01:27:52 INFO : Local file system at /tmp/rclone588269293/dir2: Server side directory move failed - fallback to file moves: can't copy directory - destination already exists 2024/12/13 01:27:52 DEBUG : file1.txt: Need to transfer - File not found at Destination 2024/12/13 01:27:52 INFO : file1.txt: Moved (server-side) 2024/12/13 01:27:52 DEBUG : Local file system at /tmp/rclone588269293/dir2: Waiting for checks to finish 2024/12/13 01:27:52 DEBUG : Local file system at /tmp/rclone588269293/dir2: Waiting for transfers to finish --- PASS: TestServerSideMoveLocal (0.43s) === RUN TestMoveWithDeleteEmptySrcDirs run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-nuguwer9fuxa'", Local "Local file system at /tmp/rclone588269293", Modify Window "1ms" 2024/12/13 01:27:53 DEBUG : Added delayed dir = "nested", newDst= 2024/12/13 01:27:53 DEBUG : Added delayed dir = "sub dir", newDst= 2024/12/13 01:27:53 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2024/12/13 01:27:53 DEBUG : Added delayed dir = "nested/sub dir", newDst= 2024/12/13 01:27:53 DEBUG : nested/sub dir/file: Need to transfer - File not found at Destination 2024/12/13 01:27:53 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-nuguwer9fuxa': Waiting for checks to finish 2024/12/13 01:27:53 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-nuguwer9fuxa': Waiting for transfers to finish 2024/12/13 01:27:56 DEBUG : sub dir/hello world: md5 = 88e5dca99ae4f6e9f94e2424e109f9db OK 2024/12/13 01:27:56 INFO : sub dir/hello world: Copied (new) 2024/12/13 01:27:56 INFO : sub dir/hello world: Deleted 2024/12/13 01:27:58 DEBUG : nested/sub dir/file: md5 = 61aafe40a95eb1dff42cf9585cbf60fb OK 2024/12/13 01:27:58 INFO : nested/sub dir/file: Copied (new) 2024/12/13 01:27:58 INFO : nested/sub dir/file: Deleted 2024/12/13 01:27:59 INFO : nested/sub dir: Set directory modification time (using DirSetModTime) 2024/12/13 01:27:59 INFO : sub dir: Set directory modification time (using DirSetModTime) 2024/12/13 01:27:59 INFO : nested: Set directory modification time (using DirSetModTime) 2024/12/13 01:27:59 INFO : sub dir: Removing directory 2024/12/13 01:27:59 INFO : nested/sub dir: Removing directory 2024/12/13 01:27:59 INFO : nested: Removing directory 2024/12/13 01:27:59 DEBUG : Local file system at /tmp/rclone588269293: deleted 3 directories run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-nuguwer9fuxa'", Local "Local file system at /tmp/rclone588269293", Modify Window "1ms" 2024/12/13 01:28:02 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" 2024/12/13 01:28:03 DEBUG : 37qp6d1gohacv723ij3brofbu8/14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "ftp4kuv8se7tqduu6pmmcvjsmk" 2024/12/13 01:28:04 DEBUG : 37qp6d1gohacv723ij3brofbu8: Rmdir: contains trashed file: "14begaa36ih249fgrnfk6nulg0" --- PASS: TestMoveWithDeleteEmptySrcDirs (12.59s) === RUN TestMoveWithoutDeleteEmptySrcDirs run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-nuguwer9fuxa'", Local "Local file system at /tmp/rclone588269293", Modify Window "1ms" 2024/12/13 01:28:06 DEBUG : Added delayed dir = "nested", newDst= 2024/12/13 01:28:06 DEBUG : Added delayed dir = "sub dir", newDst= 2024/12/13 01:28:06 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2024/12/13 01:28:06 DEBUG : Added delayed dir = "nested/sub dir", newDst= 2024/12/13 01:28:06 DEBUG : nested/sub dir/file: Need to transfer - File not found at Destination 2024/12/13 01:28:06 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-nuguwer9fuxa': Waiting for checks to finish 2024/12/13 01:28:06 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-nuguwer9fuxa': Waiting for transfers to finish 2024/12/13 01:28:08 DEBUG : sub dir/hello world: md5 = 5bcc31a614ab678b4f206a3654e977bb OK 2024/12/13 01:28:08 INFO : sub dir/hello world: Copied (new) 2024/12/13 01:28:08 INFO : sub dir/hello world: Deleted 2024/12/13 01:28:11 DEBUG : nested/sub dir/file: md5 = f11a6a6aab4712fc80c9a97d520175db OK 2024/12/13 01:28:11 INFO : nested/sub dir/file: Copied (new) 2024/12/13 01:28:11 INFO : nested/sub dir/file: Deleted 2024/12/13 01:28:12 INFO : nested/sub dir: Set directory modification time (using DirSetModTime) 2024/12/13 01:28:12 INFO : nested: Set directory modification time (using DirSetModTime) 2024/12/13 01:28:12 INFO : sub dir: Set directory modification time (using DirSetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-nuguwer9fuxa'", Local "Local file system at /tmp/rclone588269293", Modify Window "1ms" 2024/12/13 01:28:15 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" 2024/12/13 01:28:16 DEBUG : 37qp6d1gohacv723ij3brofbu8/14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "ftp4kuv8se7tqduu6pmmcvjsmk" 2024/12/13 01:28:17 DEBUG : 37qp6d1gohacv723ij3brofbu8: Rmdir: contains trashed file: "14begaa36ih249fgrnfk6nulg0" --- PASS: TestMoveWithoutDeleteEmptySrcDirs (12.90s) === RUN TestMoveWithIgnoreExisting run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-nuguwer9fuxa'", Local "Local file system at /tmp/rclone588269293", Modify Window "1ms" 2024/12/13 01:28:19 DEBUG : existing: Need to transfer - File not found at Destination 2024/12/13 01:28:19 DEBUG : existing-b: Need to transfer - File not found at Destination 2024/12/13 01:28:19 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-nuguwer9fuxa': Waiting for checks to finish 2024/12/13 01:28:19 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-nuguwer9fuxa': Waiting for transfers to finish 2024/12/13 01:28:20 DEBUG : existing-b: md5 = f895bb239e8df51d9e94ea64fd3839d3 OK 2024/12/13 01:28:20 INFO : existing-b: Copied (new) 2024/12/13 01:28:20 INFO : existing-b: Deleted 2024/12/13 01:28:20 DEBUG : existing: md5 = f402f66e8cee94f19ee2504932adc26e OK 2024/12/13 01:28:20 INFO : existing: Copied (new) 2024/12/13 01:28:20 INFO : existing: Deleted 2024/12/13 01:28:21 DEBUG : existing: Destination exists, skipping 2024/12/13 01:28:21 DEBUG : existing: Not removing source file as destination file exists and --ignore-existing is set 2024/12/13 01:28:21 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-nuguwer9fuxa': Waiting for checks to finish 2024/12/13 01:28:21 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-nuguwer9fuxa': Waiting for transfers to finish 2024/12/13 01:28:21 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-nuguwer9fuxa'", Local "Local file system at /tmp/rclone588269293", Modify Window "1ms" --- PASS: TestMoveWithIgnoreExisting (4.79s) === RUN TestServerSideMove run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-nuguwer9fuxa'", Local "Local file system at /tmp/rclone588269293", Modify Window "1ms" 2024/12/13 01:28:23 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-pifasar0vaku" 2024/12/13 01:28:23 DEBUG : Creating backend with remote "TestDrive:crypt/6ftlf2qcse1t1jqu8d76p7koarsuu0r78akusfs6l2g5pk9p474g" 2024/12/13 01:28:26 DEBUG : potato2: md5 = b9229b3f6820bd77c3e6a22d6ff355b1 OK 2024/12/13 01:28:28 DEBUG : empty space: md5 = 091e3b7f3fbca09a08fb1f4ee6d9e143 OK 2024/12/13 01:28:30 DEBUG : potato3: md5 = cc41317b30d2422166514ae59290b70e OK sync_test.go:1705: Server side move (if possible) Encrypted drive 'TestCryptDrive:rclone-test-nuguwer9fuxa' -> Encrypted drive 'TestCryptDrive:rclone-test-pifasar0vaku' 2024/12/13 01:28:33 DEBUG : empty space: md5 = 089a0de2d36fb88f2375d902f014d41e OK 2024/12/13 01:28:34 DEBUG : potato3: md5 = 9848157de9ee130485e8ed460c003536 OK 2024/12/13 01:28:35 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pifasar0vaku': Using server-side directory move 2024/12/13 01:28:35 INFO : Encrypted drive 'TestCryptDrive:rclone-test-pifasar0vaku': Server side directory move failed - fallback to file moves: can't copy directory - destination already exists 2024/12/13 01:28:35 DEBUG : potato2: Need to transfer - File not found at Destination 2024/12/13 01:28:35 DEBUG : empty space: Size and modification time the same (differ by 0s, within tolerance 1ms) 2024/12/13 01:28:35 DEBUG : empty space: Unchanged skipping 2024/12/13 01:28:35 DEBUG : potato3: Sizes differ (src 68 vs dst 60) 2024/12/13 01:28:35 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pifasar0vaku': Waiting for checks to finish 2024/12/13 01:28:35 INFO : potato3: Deleted 2024/12/13 01:28:36 INFO : empty space: Deleted 2024/12/13 01:28:36 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pifasar0vaku': Waiting for transfers to finish 2024/12/13 01:28:36 INFO : potato2: Moved (server-side) 2024/12/13 01:28:36 INFO : potato3: Moved (server-side) 2024/12/13 01:28:37 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-vehexak9fuke" 2024/12/13 01:28:37 DEBUG : Creating backend with remote "TestDrive:crypt/pmd1n40qvt7h517eaj6dn9msnphg28rre495sehq2q5n945euin0" 2024/12/13 01:28:38 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vehexak9fuke': Using server-side directory move 2024/12/13 01:28:39 INFO : Encrypted drive 'TestCryptDrive:rclone-test-vehexak9fuke': Server side directory move succeeded 2024/12/13 01:28:40 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vehexak9fuke': Purge remote 2024/12/13 01:28:40 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pifasar0vaku': Purge remote 2024/12/13 01:28:41 NOTICE: purge failed: directory not found --- PASS: TestServerSideMove (18.03s) === RUN TestServerSideMoveWithFilter run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-nuguwer9fuxa'", Local "Local file system at /tmp/rclone588269293", Modify Window "1ms" 2024/12/13 01:28:41 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-regeqem0tevi" 2024/12/13 01:28:41 DEBUG : Creating backend with remote "TestDrive:crypt/3p8rcef384k39dga2r1k32jpu84ecde5jga7g2lue2e4avcdc8eg" 2024/12/13 01:28:44 DEBUG : potato2: md5 = a0526682333c5c4f69749d246d9394ce OK 2024/12/13 01:28:46 DEBUG : empty space: md5 = c365071b48dc79bcd5dedd598282deea OK 2024/12/13 01:28:48 DEBUG : potato3: md5 = 4135490e6ffaf22ea864af0fbbd4128a OK sync_test.go:1705: Server side move (if possible) Encrypted drive 'TestCryptDrive:rclone-test-nuguwer9fuxa' -> Encrypted drive 'TestCryptDrive:rclone-test-regeqem0tevi' 2024/12/13 01:28:51 DEBUG : empty space: md5 = 3951356382deee18da60866e5008a6f1 OK 2024/12/13 01:28:52 DEBUG : potato3: md5 = 810683956a108e5e769b44d102e33d11 OK 2024/12/13 01:28:53 DEBUG : empty space: Excluded (Size Filter) 2024/12/13 01:28:53 DEBUG : empty space: Excluded 2024/12/13 01:28:53 DEBUG : empty space: Excluded (Size Filter) 2024/12/13 01:28:53 DEBUG : empty space: Excluded 2024/12/13 01:28:53 DEBUG : potato2: Need to transfer - File not found at Destination 2024/12/13 01:28:53 DEBUG : potato3: Sizes differ (src 68 vs dst 60) 2024/12/13 01:28:53 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-regeqem0tevi': Waiting for checks to finish 2024/12/13 01:28:53 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-regeqem0tevi': Waiting for transfers to finish 2024/12/13 01:28:53 INFO : potato3: Deleted 2024/12/13 01:28:54 INFO : potato2: Moved (server-side) 2024/12/13 01:28:54 INFO : potato3: Moved (server-side) 2024/12/13 01:28:55 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-wihetav9tuda" 2024/12/13 01:28:55 DEBUG : Creating backend with remote "TestDrive:crypt/nf6jurf04vfle2f7ks8bvivguhmhogkhbq82mf1unsnr775q5uog" 2024/12/13 01:28:56 DEBUG : empty space: Excluded (Size Filter) 2024/12/13 01:28:56 DEBUG : empty space: Excluded 2024/12/13 01:28:56 DEBUG : potato2: Need to transfer - File not found at Destination 2024/12/13 01:28:56 DEBUG : potato3: Need to transfer - File not found at Destination 2024/12/13 01:28:56 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wihetav9tuda': Waiting for checks to finish 2024/12/13 01:28:56 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wihetav9tuda': Waiting for transfers to finish 2024/12/13 01:28:58 INFO : potato3: Moved (server-side) 2024/12/13 01:28:58 INFO : potato2: Moved (server-side) 2024/12/13 01:28:59 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wihetav9tuda': Purge remote 2024/12/13 01:28:59 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-regeqem0tevi': Purge remote --- PASS: TestServerSideMoveWithFilter (19.84s) === RUN TestServerSideMoveDeleteEmptySourceDirs run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-nuguwer9fuxa'", Local "Local file system at /tmp/rclone588269293", Modify Window "1ms" 2024/12/13 01:29:01 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-raxanex3kima" 2024/12/13 01:29:01 DEBUG : Creating backend with remote "TestDrive:crypt/pl53krac4q3h7gnqumdb2lns3d03l2im896ahqcuk66tlkqvg5ig" 2024/12/13 01:29:04 DEBUG : potato2: md5 = 9b1e29bf6ac39454982e1dd839174f2b OK 2024/12/13 01:29:05 DEBUG : empty space: md5 = b91308bcd77b9e6d05fdb1b8f30fc4b7 OK 2024/12/13 01:29:07 DEBUG : potato3: md5 = 666a26ce62110b9cde6270039129adf1 OK 2024/12/13 01:29:07 DEBUG : tomatoDir: Making directory sync_test.go:1705: Server side move (if possible) Encrypted drive 'TestCryptDrive:rclone-test-nuguwer9fuxa' -> Encrypted drive 'TestCryptDrive:rclone-test-raxanex3kima' 2024/12/13 01:29:12 DEBUG : empty space: md5 = be14266efa841db6b0c92566ab845fb3 OK 2024/12/13 01:29:13 DEBUG : potato3: md5 = 5f2e84d01337f5e2a295ea506b947026 OK 2024/12/13 01:29:14 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-raxanex3kima': Using server-side directory move 2024/12/13 01:29:14 INFO : Encrypted drive 'TestCryptDrive:rclone-test-raxanex3kima': Server side directory move failed - fallback to file moves: can't copy directory - destination already exists 2024/12/13 01:29:14 DEBUG : potato2: Need to transfer - File not found at Destination 2024/12/13 01:29:14 DEBUG : Added delayed dir = "tomatoDir", newDst= 2024/12/13 01:29:14 DEBUG : empty space: Size and modification time the same (differ by 0s, within tolerance 1ms) 2024/12/13 01:29:14 DEBUG : empty space: Unchanged skipping 2024/12/13 01:29:14 DEBUG : potato3: Sizes differ (src 68 vs dst 60) 2024/12/13 01:29:14 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-raxanex3kima': Waiting for checks to finish 2024/12/13 01:29:14 INFO : empty space: Deleted 2024/12/13 01:29:14 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-raxanex3kima': Waiting for transfers to finish 2024/12/13 01:29:14 INFO : potato3: Deleted 2024/12/13 01:29:15 INFO : potato2: Moved (server-side) 2024/12/13 01:29:15 INFO : potato3: Moved (server-side) 2024/12/13 01:29:15 INFO : tomatoDir: Removing directory 2024/12/13 01:29:16 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-nuguwer9fuxa': deleted 1 directories 2024/12/13 01:29:17 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-petejam7nazu" 2024/12/13 01:29:17 DEBUG : Creating backend with remote "TestDrive:crypt/92uh1olvnhj9bs1vn7vpo46ub8kpc071dffrqv4gomcvps1qq860" 2024/12/13 01:29:18 DEBUG : tomatoDir: Making directory 2024/12/13 01:29:19 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-petejam7nazu': Using server-side directory move 2024/12/13 01:29:20 INFO : Encrypted drive 'TestCryptDrive:rclone-test-petejam7nazu': Server side directory move succeeded 2024/12/13 01:29:21 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-petejam7nazu': Purge remote 2024/12/13 01:29:22 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-raxanex3kima': Purge remote 2024/12/13 01:29:22 NOTICE: purge failed: directory not found --- PASS: TestServerSideMoveDeleteEmptySourceDirs (21.45s) === RUN TestServerSideMoveOverlap run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-nuguwer9fuxa'", Local "Local file system at /tmp/rclone588269293", Modify Window "1ms" sync_test.go:1910: Skipping test as remote supports DirMove --- SKIP: TestServerSideMoveOverlap (0.49s) === RUN TestSyncOverlap run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-nuguwer9fuxa'", Local "Local file system at /tmp/rclone588269293", Modify Window "1ms" 2024/12/13 01:29:23 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-nuguwer9fuxa/rclone-sync-test" 2024/12/13 01:29:23 DEBUG : Creating backend with remote "TestDrive:crypt/sinc28mqh1lj92nob4gqgdh328leac69b1ffmoeuv12ubd3d6640/i7355aa0sb89uagn75vfjqr6s3e3e1h2et8in57abn1fe8qfego0" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-nuguwer9fuxa'", Local "Local file system at /tmp/rclone588269293", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-nuguwer9fuxa'", Local "Local file system at /tmp/rclone588269293", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-nuguwer9fuxa'", Local "Local file system at /tmp/rclone588269293", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-nuguwer9fuxa'", Local "Local file system at /tmp/rclone588269293", Modify Window "1ms" --- PASS: TestSyncOverlap (3.83s) === RUN TestSyncOverlapWithFilter run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-nuguwer9fuxa'", Local "Local file system at /tmp/rclone588269293", Modify Window "1ms" 2024/12/13 01:29:27 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-nuguwer9fuxa/rclone-sync-test" 2024/12/13 01:29:27 DEBUG : Config file has changed externally - reloading 2024/12/13 01:29:27 DEBUG : Creating backend with remote "TestDrive:crypt/sinc28mqh1lj92nob4gqgdh328leac69b1ffmoeuv12ubd3d6640/i7355aa0sb89uagn75vfjqr6s3e3e1h2et8in57abn1fe8qfego0" 2024/12/13 01:29:29 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-nuguwer9fuxa/rclone-sync-test-include/layer2" 2024/12/13 01:29:29 DEBUG : Creating backend with remote "TestDrive:crypt/sinc28mqh1lj92nob4gqgdh328leac69b1ffmoeuv12ubd3d6640/khf2vlblvnbf9ftevqm0htmss73hj1j5a7q328e4ohrgs7e2loe0/n01jpl9202nn9ec1rb75h0f1c4" 2024/12/13 01:29:33 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-nuguwer9fuxa/rclone-sync-test-ignore-file" 2024/12/13 01:29:33 DEBUG : Creating backend with remote "TestDrive:crypt/sinc28mqh1lj92nob4gqgdh328leac69b1ffmoeuv12ubd3d6640/kmf11jujl9uha3tjganvgpkn45bu778hb5vb5riug1c26b38k7sg" 2024/12/13 01:29:38 DEBUG : rclone-sync-test-ignore-file/.ignore: md5 = ed2b5984ef37b0d03834e35386884ee4 OK 2024/12/13 01:29:39 DEBUG : rclone-sync-test-ignore-file: Excluded 2024/12/13 01:29:39 DEBUG : rclone-sync-test: Excluded 2024/12/13 01:29:39 DEBUG : Added delayed dir = "rclone-sync-test-include", newDst= 2024/12/13 01:29:40 DEBUG : rclone-sync-test-include/layer2: Excluded 2024/12/13 01:29:40 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-nuguwer9fuxa/rclone-sync-test': Waiting for checks to finish 2024/12/13 01:29:40 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-nuguwer9fuxa/rclone-sync-test': Waiting for transfers to finish 2024/12/13 01:29:40 DEBUG : Waiting for deletions to finish 2024/12/13 01:29:40 INFO : There was nothing to transfer 2024/12/13 01:29:40 DEBUG : rclone-sync-test-ignore-file: Excluded 2024/12/13 01:29:41 DEBUG : rclone-sync-test: Excluded 2024/12/13 01:29:41 DEBUG : rclone-sync-test-include/layer2: Excluded 2024/12/13 01:29:41 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-nuguwer9fuxa': Waiting for checks to finish 2024/12/13 01:29:41 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-nuguwer9fuxa': Waiting for transfers to finish 2024/12/13 01:29:41 DEBUG : Waiting for deletions to finish 2024/12/13 01:29:41 INFO : rclone-sync-test-include: Removing directory 2024/12/13 01:29:42 DEBUG : khf2vlblvnbf9ftevqm0htmss73hj1j5a7q328e4ohrgs7e2loe0: Rmdir: contains file: "n01jpl9202nn9ec1rb75h0f1c4" 2024/12/13 01:29:42 DEBUG : rclone-sync-test-include: Failed to Rmdir: directory not empty 2024/12/13 01:29:42 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-nuguwer9fuxa': failed to delete 1 directories 2024/12/13 01:29:42 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-nuguwer9fuxa'", Local "Local file system at /tmp/rclone588269293", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-nuguwer9fuxa'", Local "Local file system at /tmp/rclone588269293", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-nuguwer9fuxa'", Local "Local file system at /tmp/rclone588269293", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-nuguwer9fuxa'", Local "Local file system at /tmp/rclone588269293", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-nuguwer9fuxa'", Local "Local file system at /tmp/rclone588269293", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-nuguwer9fuxa'", Local "Local file system at /tmp/rclone588269293", Modify Window "1ms" 2024/12/13 01:29:42 DEBUG : rclone-sync-test-ignore-file: Excluded 2024/12/13 01:29:43 DEBUG : rclone-sync-test: Excluded 2024/12/13 01:29:43 DEBUG : Added delayed dir = "rclone-sync-test-include", newDst= 2024/12/13 01:29:43 DEBUG : rclone-sync-test-include/layer2: Excluded 2024/12/13 01:29:43 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-nuguwer9fuxa/rclone-sync-test-include/layer2': Waiting for checks to finish 2024/12/13 01:29:43 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-nuguwer9fuxa/rclone-sync-test-include/layer2': Waiting for transfers to finish 2024/12/13 01:29:43 DEBUG : Waiting for deletions to finish 2024/12/13 01:29:43 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-nuguwer9fuxa'", Local "Local file system at /tmp/rclone588269293", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-nuguwer9fuxa'", Local "Local file system at /tmp/rclone588269293", Modify Window "1ms" 2024/12/13 01:29:44 DEBUG : rclone-sync-test-ignore-file: Excluded 2024/12/13 01:29:45 DEBUG : rclone-sync-test: Excluded 2024/12/13 01:29:45 DEBUG : rclone-sync-test-include/layer2: Excluded 2024/12/13 01:29:45 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-nuguwer9fuxa': Waiting for checks to finish 2024/12/13 01:29:45 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-nuguwer9fuxa': Waiting for transfers to finish 2024/12/13 01:29:45 DEBUG : Waiting for deletions to finish 2024/12/13 01:29:45 INFO : rclone-sync-test-include: Removing directory 2024/12/13 01:29:45 DEBUG : khf2vlblvnbf9ftevqm0htmss73hj1j5a7q328e4ohrgs7e2loe0: Rmdir: contains file: "n01jpl9202nn9ec1rb75h0f1c4" 2024/12/13 01:29:45 DEBUG : rclone-sync-test-include: Failed to Rmdir: directory not empty 2024/12/13 01:29:45 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-nuguwer9fuxa': failed to delete 1 directories 2024/12/13 01:29:45 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-nuguwer9fuxa'", Local "Local file system at /tmp/rclone588269293", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-nuguwer9fuxa'", Local "Local file system at /tmp/rclone588269293", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-nuguwer9fuxa'", Local "Local file system at /tmp/rclone588269293", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-nuguwer9fuxa'", Local "Local file system at /tmp/rclone588269293", Modify Window "1ms" 2024/12/13 01:29:46 DEBUG : : Excluded 2024/12/13 01:29:46 DEBUG : rclone-sync-test-ignore-file: Excluded 2024/12/13 01:29:47 DEBUG : rclone-sync-test: Excluded 2024/12/13 01:29:47 DEBUG : Added delayed dir = "rclone-sync-test-include", newDst= 2024/12/13 01:29:47 DEBUG : rclone-sync-test-include/layer2: Excluded 2024/12/13 01:29:47 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-nuguwer9fuxa/rclone-sync-test-ignore-file': Waiting for checks to finish 2024/12/13 01:29:47 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-nuguwer9fuxa/rclone-sync-test-ignore-file': Waiting for transfers to finish 2024/12/13 01:29:47 DEBUG : Waiting for deletions to finish 2024/12/13 01:29:47 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-nuguwer9fuxa'", Local "Local file system at /tmp/rclone588269293", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-nuguwer9fuxa'", Local "Local file system at /tmp/rclone588269293", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-nuguwer9fuxa'", Local "Local file system at /tmp/rclone588269293", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-nuguwer9fuxa'", Local "Local file system at /tmp/rclone588269293", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-nuguwer9fuxa'", Local "Local file system at /tmp/rclone588269293", Modify Window "1ms" 2024/12/13 01:29:49 DEBUG : khf2vlblvnbf9ftevqm0htmss73hj1j5a7q328e4ohrgs7e2loe0: Rmdir: contains trashed file: "n01jpl9202nn9ec1rb75h0f1c4" 2024/12/13 01:29:50 DEBUG : kmf11jujl9uha3tjganvgpkn45bu778hb5vb5riug1c26b38k7sg: Rmdir: contains trashed file: "i0t74httmdlljg425j6tg570d8" --- PASS: TestSyncOverlapWithFilter (32.84s) === RUN TestSyncCompareDest run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-nuguwer9fuxa'", Local "Local file system at /tmp/rclone588269293", Modify Window "1ms" 2024/12/13 01:30:00 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-nuguwer9fuxa/dst" 2024/12/13 01:30:00 DEBUG : Config file has changed externally - reloading 2024/12/13 01:30:00 DEBUG : Creating backend with remote "TestDrive:crypt/sinc28mqh1lj92nob4gqgdh328leac69b1ffmoeuv12ubd3d6640/31u3jie661vd5p8j7rtc3hgbh0" 2024/12/13 01:30:01 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-nuguwer9fuxa/CompareDest" 2024/12/13 01:30:01 DEBUG : Creating backend with remote "TestDrive:crypt/sinc28mqh1lj92nob4gqgdh328leac69b1ffmoeuv12ubd3d6640/gveqi14airsml4bgu7krj116o8" 2024/12/13 01:30:03 DEBUG : one: Need to transfer - File not found at Destination 2024/12/13 01:30:03 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-nuguwer9fuxa/dst': Waiting for checks to finish 2024/12/13 01:30:03 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-nuguwer9fuxa/dst': Waiting for transfers to finish 2024/12/13 01:30:06 DEBUG : one: md5 = 65953715c873820f0e6ac16828da3c1f OK 2024/12/13 01:30:06 INFO : one: Copied (new) 2024/12/13 01:30:06 DEBUG : Waiting for deletions to finish 2024/12/13 01:30:07 DEBUG : one: Sizes differ (src 5 vs dst 3) 2024/12/13 01:30:07 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-nuguwer9fuxa/dst': Waiting for checks to finish 2024/12/13 01:30:08 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-nuguwer9fuxa/dst': Waiting for transfers to finish 2024/12/13 01:30:09 DEBUG : one: md5 = 1dbf7a1102099fb3fa09c30d5fcdbd9f OK 2024/12/13 01:30:09 INFO : one: Copied (replaced existing) 2024/12/13 01:30:09 DEBUG : Waiting for deletions to finish 2024/12/13 01:30:11 DEBUG : dst/one: md5 = b7ed4614aa675d25a904dc0be4ce1d7e OK 2024/12/13 01:30:14 DEBUG : CompareDest/one: md5 = 4fa8a5240653a9afa1c2379447aca85d OK 2024/12/13 01:30:14 DEBUG : one: Sizes differ (src 5 vs dst 3) 2024/12/13 01:30:14 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-nuguwer9fuxa/dst': Waiting for checks to finish 2024/12/13 01:30:15 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2024/12/13 01:30:15 DEBUG : one: Destination found in --compare-dest, skipping 2024/12/13 01:30:15 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-nuguwer9fuxa/dst': Waiting for transfers to finish 2024/12/13 01:30:15 DEBUG : Waiting for deletions to finish 2024/12/13 01:30:15 INFO : There was nothing to transfer 2024/12/13 01:30:17 DEBUG : CompareDest/two: md5 = 8f0d6cf7eb6aafa50b8766d34cf8f821 OK 2024/12/13 01:30:18 DEBUG : two: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2024/12/13 01:30:18 DEBUG : two: Destination found in --compare-dest, skipping 2024/12/13 01:30:18 DEBUG : one: Sizes differ (src 5 vs dst 3) 2024/12/13 01:30:18 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-nuguwer9fuxa/dst': Waiting for checks to finish 2024/12/13 01:30:18 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2024/12/13 01:30:18 DEBUG : one: Destination found in --compare-dest, skipping 2024/12/13 01:30:18 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-nuguwer9fuxa/dst': Waiting for transfers to finish 2024/12/13 01:30:18 DEBUG : Waiting for deletions to finish 2024/12/13 01:30:18 INFO : There was nothing to transfer 2024/12/13 01:30:19 DEBUG : two: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2024/12/13 01:30:19 DEBUG : two: Destination found in --compare-dest, skipping 2024/12/13 01:30:19 DEBUG : one: Sizes differ (src 5 vs dst 3) 2024/12/13 01:30:19 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-nuguwer9fuxa/dst': Waiting for checks to finish 2024/12/13 01:30:19 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2024/12/13 01:30:19 DEBUG : one: Destination found in --compare-dest, skipping 2024/12/13 01:30:19 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-nuguwer9fuxa/dst': Waiting for transfers to finish 2024/12/13 01:30:19 DEBUG : Waiting for deletions to finish 2024/12/13 01:30:19 INFO : There was nothing to transfer sync_test.go:2175: No hash on uploaded file so skipping compare timestamp test 2024/12/13 01:30:21 DEBUG : two: Sizes differ (src 5 vs dst 3) 2024/12/13 01:30:21 DEBUG : two: Need to transfer - File not found at Destination 2024/12/13 01:30:21 DEBUG : one: Sizes differ (src 5 vs dst 3) 2024/12/13 01:30:21 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-nuguwer9fuxa/dst': Waiting for checks to finish 2024/12/13 01:30:21 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2024/12/13 01:30:21 DEBUG : one: Destination found in --compare-dest, skipping 2024/12/13 01:30:21 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-nuguwer9fuxa/dst': Waiting for transfers to finish 2024/12/13 01:30:23 DEBUG : two: md5 = 93e0bd1c7e1b687951e5a51e67adf115 OK 2024/12/13 01:30:23 INFO : two: Copied (new) 2024/12/13 01:30:23 DEBUG : Waiting for deletions to finish 2024/12/13 01:30:26 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k" 2024/12/13 01:30:26 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" 2024/12/13 01:30:27 DEBUG : gveqi14airsml4bgu7krj116o8: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k" 2024/12/13 01:30:27 DEBUG : gveqi14airsml4bgu7krj116o8: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" --- PASS: TestSyncCompareDest (28.88s) === RUN TestSyncMultipleCompareDest run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-nuguwer9fuxa'", Local "Local file system at /tmp/rclone588269293", Modify Window "1ms" 2024/12/13 01:30:31 DEBUG : pre-dest1/1: md5 = 23a5115c4bcf2f5e14bf2ebe24dc179e OK 2024/12/13 01:30:34 DEBUG : pre-dest2/2: md5 = 3bb6fb339871da587c0964e2eb1e53d6 OK 2024/12/13 01:30:34 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-nuguwer9fuxa/dest" 2024/12/13 01:30:34 DEBUG : Creating backend with remote "TestDrive:crypt/sinc28mqh1lj92nob4gqgdh328leac69b1ffmoeuv12ubd3d6640/rg03c1jvnehrrc617i0lnqjddc" 2024/12/13 01:30:36 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-nuguwer9fuxa/pre-dest1" 2024/12/13 01:30:36 DEBUG : Creating backend with remote "TestDrive:crypt/sinc28mqh1lj92nob4gqgdh328leac69b1ffmoeuv12ubd3d6640/bbnblvh6k061ssopqrp18kd7gc" 2024/12/13 01:30:37 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-nuguwer9fuxa/pre-dest2" 2024/12/13 01:30:37 DEBUG : Creating backend with remote "TestDrive:crypt/sinc28mqh1lj92nob4gqgdh328leac69b1ffmoeuv12ubd3d6640/dgicm1h6b5ejvlltm8eeif0bnk" 2024/12/13 01:30:38 DEBUG : 1: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2024/12/13 01:30:38 DEBUG : 1: Destination found in --compare-dest, skipping 2024/12/13 01:30:39 DEBUG : 2: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2024/12/13 01:30:39 DEBUG : 2: Destination found in --compare-dest, skipping 2024/12/13 01:30:39 DEBUG : 3: Need to transfer - File not found at Destination 2024/12/13 01:30:39 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-nuguwer9fuxa/dest': Waiting for checks to finish 2024/12/13 01:30:39 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-nuguwer9fuxa/dest': Waiting for transfers to finish 2024/12/13 01:30:42 DEBUG : 3: md5 = 47e16cfe59ccba56718b28dff0e791dd OK 2024/12/13 01:30:42 INFO : 3: Copied (new) 2024/12/13 01:30:42 DEBUG : Waiting for deletions to finish 2024/12/13 01:30:45 DEBUG : dgicm1h6b5ejvlltm8eeif0bnk: Rmdir: contains trashed file: "1ghu8geql9vrl726n32nrf65bc" 2024/12/13 01:30:46 DEBUG : bbnblvh6k061ssopqrp18kd7gc: Rmdir: contains trashed file: "skbfko3oil7es0lj68ob574sro" 2024/12/13 01:30:47 DEBUG : rg03c1jvnehrrc617i0lnqjddc: Rmdir: contains trashed file: "g072p7hmjchlnj0gibe64c1epg" --- PASS: TestSyncMultipleCompareDest (19.37s) === RUN TestSyncCopyDest run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-nuguwer9fuxa'", Local "Local file system at /tmp/rclone588269293", Modify Window "1ms" 2024/12/13 01:30:48 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-nuguwer9fuxa/dst" 2024/12/13 01:30:48 DEBUG : Creating backend with remote "TestDrive:crypt/sinc28mqh1lj92nob4gqgdh328leac69b1ffmoeuv12ubd3d6640/31u3jie661vd5p8j7rtc3hgbh0" 2024/12/13 01:30:49 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-nuguwer9fuxa/CopyDest" 2024/12/13 01:30:49 DEBUG : Creating backend with remote "TestDrive:crypt/sinc28mqh1lj92nob4gqgdh328leac69b1ffmoeuv12ubd3d6640/d09o6po3f7bm6ce32vdgs8h9ls" 2024/12/13 01:30:51 DEBUG : one: Need to transfer - File not found at Destination 2024/12/13 01:30:51 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-nuguwer9fuxa/dst': Waiting for checks to finish 2024/12/13 01:30:51 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-nuguwer9fuxa/dst': Waiting for transfers to finish 2024/12/13 01:30:54 DEBUG : one: md5 = 3f8a1c2c8725c01e045ddb4a73dff77a OK 2024/12/13 01:30:54 INFO : one: Copied (new) 2024/12/13 01:30:54 DEBUG : Waiting for deletions to finish 2024/12/13 01:30:55 DEBUG : one: Sizes differ (src 5 vs dst 3) 2024/12/13 01:30:55 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-nuguwer9fuxa/dst': Waiting for checks to finish 2024/12/13 01:30:56 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-nuguwer9fuxa/dst': Waiting for transfers to finish 2024/12/13 01:30:57 DEBUG : one: md5 = 8d111eebce2903da59a8c95b6a96edac OK 2024/12/13 01:30:57 INFO : one: Copied (replaced existing) 2024/12/13 01:30:57 DEBUG : Waiting for deletions to finish 2024/12/13 01:30:59 DEBUG : dst/one: md5 = 95d7f62eaf7d56b8711fe6908f34c2c8 OK 2024/12/13 01:31:02 DEBUG : CopyDest/one: md5 = 64c65ecdc9a1c49731e8197f11772103 OK 2024/12/13 01:31:02 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-nuguwer9fuxa/BackupDir" 2024/12/13 01:31:02 DEBUG : Creating backend with remote "TestDrive:crypt/sinc28mqh1lj92nob4gqgdh328leac69b1ffmoeuv12ubd3d6640/s6dbk3lfi7c9kfvo6j7bla9m0g" 2024/12/13 01:31:04 DEBUG : one: Sizes differ (src 5 vs dst 3) 2024/12/13 01:31:04 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-nuguwer9fuxa/dst': Waiting for checks to finish 2024/12/13 01:31:05 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2024/12/13 01:31:05 DEBUG : one: Sizes differ (src 5 vs dst 3) 2024/12/13 01:31:07 INFO : one: Moved (server-side) 2024/12/13 01:31:08 INFO : one: Copied (server-side copy) 2024/12/13 01:31:08 DEBUG : one: Destination found in --copy-dest, using server-side copy 2024/12/13 01:31:08 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-nuguwer9fuxa/dst': Waiting for transfers to finish 2024/12/13 01:31:08 DEBUG : Waiting for deletions to finish 2024/12/13 01:31:10 DEBUG : CopyDest/two: md5 = 2ede777f4e4e4192f8f268105fd124ac OK 2024/12/13 01:31:11 DEBUG : two: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2024/12/13 01:31:13 INFO : two: Copied (server-side copy) 2024/12/13 01:31:13 DEBUG : two: Destination found in --copy-dest, using server-side copy 2024/12/13 01:31:13 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2024/12/13 01:31:13 DEBUG : one: Unchanged skipping 2024/12/13 01:31:13 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-nuguwer9fuxa/dst': Waiting for checks to finish 2024/12/13 01:31:13 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-nuguwer9fuxa/dst': Waiting for transfers to finish 2024/12/13 01:31:13 DEBUG : Waiting for deletions to finish 2024/12/13 01:31:14 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2024/12/13 01:31:14 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-nuguwer9fuxa/dst': Waiting for checks to finish 2024/12/13 01:31:14 DEBUG : one: Unchanged skipping 2024/12/13 01:31:14 DEBUG : two: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2024/12/13 01:31:14 DEBUG : two: Unchanged skipping 2024/12/13 01:31:14 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-nuguwer9fuxa/dst': Waiting for transfers to finish 2024/12/13 01:31:14 DEBUG : Waiting for deletions to finish 2024/12/13 01:31:14 INFO : There was nothing to transfer 2024/12/13 01:31:16 DEBUG : CopyDest/three: md5 = aab80c5d14dd30819385df1e8ee71c13 OK 2024/12/13 01:31:17 DEBUG : three: Sizes differ (src 7 vs dst 5) 2024/12/13 01:31:17 DEBUG : three: Destination not found in --copy-dest 2024/12/13 01:31:17 DEBUG : three: Need to transfer - File not found at Destination 2024/12/13 01:31:17 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2024/12/13 01:31:17 DEBUG : one: Unchanged skipping 2024/12/13 01:31:17 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-nuguwer9fuxa/dst': Waiting for checks to finish 2024/12/13 01:31:17 DEBUG : two: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2024/12/13 01:31:17 DEBUG : two: Unchanged skipping 2024/12/13 01:31:17 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-nuguwer9fuxa/dst': Waiting for transfers to finish 2024/12/13 01:31:18 DEBUG : three: md5 = 5e863b019198129e630cb31f51c23a78 OK 2024/12/13 01:31:18 INFO : three: Copied (new) 2024/12/13 01:31:18 DEBUG : Waiting for deletions to finish 2024/12/13 01:31:24 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "b6jdmn2b1adrhc8vikh7edr9os" 2024/12/13 01:31:24 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k" 2024/12/13 01:31:24 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" 2024/12/13 01:31:25 DEBUG : d09o6po3f7bm6ce32vdgs8h9ls: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k" 2024/12/13 01:31:25 DEBUG : d09o6po3f7bm6ce32vdgs8h9ls: Rmdir: contains trashed file: "b6jdmn2b1adrhc8vikh7edr9os" 2024/12/13 01:31:25 DEBUG : d09o6po3f7bm6ce32vdgs8h9ls: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" 2024/12/13 01:31:26 DEBUG : s6dbk3lfi7c9kfvo6j7bla9m0g: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" --- PASS: TestSyncCopyDest (38.57s) === RUN TestSyncBackupDir run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-nuguwer9fuxa'", Local "Local file system at /tmp/rclone588269293", Modify Window "1ms" 2024/12/13 01:31:29 DEBUG : dst/one: md5 = 72bc86584b257eb490d30fdab2a208be OK 2024/12/13 01:31:31 DEBUG : dst/two: md5 = 98a88aff57e0995f1e9317431a598e5d OK 2024/12/13 01:31:33 DEBUG : dst/three.txt: md5 = 3b8275dcb2ba28c9b5c703c64c076a6d OK 2024/12/13 01:31:33 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-nuguwer9fuxa/dst" 2024/12/13 01:31:33 DEBUG : Creating backend with remote "TestDrive:crypt/sinc28mqh1lj92nob4gqgdh328leac69b1ffmoeuv12ubd3d6640/31u3jie661vd5p8j7rtc3hgbh0" 2024/12/13 01:31:34 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-nuguwer9fuxa/backup" 2024/12/13 01:31:34 DEBUG : Creating backend with remote "TestDrive:crypt/sinc28mqh1lj92nob4gqgdh328leac69b1ffmoeuv12ubd3d6640/1nrff024r7pq65ecp72fc28jb0" 2024/12/13 01:31:36 DEBUG : one: Sizes differ (src 4 vs dst 3) 2024/12/13 01:31:36 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2024/12/13 01:31:36 DEBUG : two: Unchanged skipping 2024/12/13 01:31:36 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-nuguwer9fuxa/dst': Waiting for checks to finish 2024/12/13 01:31:38 INFO : one: Moved (server-side) 2024/12/13 01:31:38 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-nuguwer9fuxa/dst': Waiting for transfers to finish 2024/12/13 01:31:40 DEBUG : one: md5 = a632223ed0138385ef45e4d0ae9bbfe2 OK 2024/12/13 01:31:40 INFO : one: Copied (new) 2024/12/13 01:31:40 DEBUG : Waiting for deletions to finish 2024/12/13 01:31:41 INFO : three.txt: Moved (server-side) 2024/12/13 01:31:41 INFO : three.txt: Moved into backup dir 2024/12/13 01:31:43 DEBUG : dst/three.txt: md5 = e8d16804fde8f248a3f7f225162aad56 OK 2024/12/13 01:31:44 DEBUG : one: Sizes differ (src 5 vs dst 4) 2024/12/13 01:31:44 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2024/12/13 01:31:44 DEBUG : two: Unchanged skipping 2024/12/13 01:31:44 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-nuguwer9fuxa/dst': Waiting for checks to finish 2024/12/13 01:31:45 INFO : one: Deleted 2024/12/13 01:31:46 INFO : one: Moved (server-side) 2024/12/13 01:31:46 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-nuguwer9fuxa/dst': Waiting for transfers to finish 2024/12/13 01:31:48 DEBUG : one: md5 = 76beee31ba67a5c20c7e0eaaea2f3f1a OK 2024/12/13 01:31:48 INFO : one: Copied (new) 2024/12/13 01:31:48 DEBUG : Waiting for deletions to finish 2024/12/13 01:31:48 INFO : three.txt: Deleted 2024/12/13 01:31:49 INFO : three.txt: Moved (server-side) 2024/12/13 01:31:49 INFO : three.txt: Moved into backup dir 2024/12/13 01:31:53 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" 2024/12/13 01:31:53 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k" 2024/12/13 01:31:54 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "tr2hj63d80ftlmvm6a952snjcc" 2024/12/13 01:31:54 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" 2024/12/13 01:31:54 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" 2024/12/13 01:31:54 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "tr2hj63d80ftlmvm6a952snjcc" --- PASS: TestSyncBackupDir (28.18s) === RUN TestSyncBackupDirWithSuffix run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-nuguwer9fuxa'", Local "Local file system at /tmp/rclone588269293", Modify Window "1ms" 2024/12/13 01:31:57 DEBUG : dst/one: md5 = c7af72c704164298fa1b96c1be93e169 OK 2024/12/13 01:31:59 DEBUG : dst/two: md5 = 985259015ca37937f596863a9566da0b OK 2024/12/13 01:32:01 DEBUG : dst/three.txt: md5 = 164008f02b7802c069b5b40a9b00e5b7 OK 2024/12/13 01:32:01 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-nuguwer9fuxa/dst" 2024/12/13 01:32:01 DEBUG : Creating backend with remote "TestDrive:crypt/sinc28mqh1lj92nob4gqgdh328leac69b1ffmoeuv12ubd3d6640/31u3jie661vd5p8j7rtc3hgbh0" 2024/12/13 01:32:02 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-nuguwer9fuxa/backup" 2024/12/13 01:32:02 DEBUG : Creating backend with remote "TestDrive:crypt/sinc28mqh1lj92nob4gqgdh328leac69b1ffmoeuv12ubd3d6640/1nrff024r7pq65ecp72fc28jb0" 2024/12/13 01:32:04 DEBUG : one: Sizes differ (src 4 vs dst 3) 2024/12/13 01:32:04 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2024/12/13 01:32:04 DEBUG : two: Unchanged skipping 2024/12/13 01:32:04 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-nuguwer9fuxa/dst': Waiting for checks to finish 2024/12/13 01:32:06 INFO : one: Moved (server-side) to: one.bak 2024/12/13 01:32:06 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-nuguwer9fuxa/dst': Waiting for transfers to finish 2024/12/13 01:32:08 DEBUG : one: md5 = 8ee35937ece5faedc3947d1bee628f0d OK 2024/12/13 01:32:08 INFO : one: Copied (new) 2024/12/13 01:32:08 DEBUG : Waiting for deletions to finish 2024/12/13 01:32:09 INFO : three.txt: Moved (server-side) to: three.txt.bak 2024/12/13 01:32:09 INFO : three.txt: Moved into backup dir 2024/12/13 01:32:11 DEBUG : dst/three.txt: md5 = 266d006eb75dfdfc72333c6031e78bb4 OK 2024/12/13 01:32:12 DEBUG : one: Sizes differ (src 5 vs dst 4) 2024/12/13 01:32:12 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2024/12/13 01:32:12 DEBUG : two: Unchanged skipping 2024/12/13 01:32:12 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-nuguwer9fuxa/dst': Waiting for checks to finish 2024/12/13 01:32:13 INFO : one.bak: Deleted 2024/12/13 01:32:14 INFO : one: Moved (server-side) to: one.bak 2024/12/13 01:32:14 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-nuguwer9fuxa/dst': Waiting for transfers to finish 2024/12/13 01:32:15 DEBUG : one: md5 = cbf461a4f680464846e97e4446960fab OK 2024/12/13 01:32:15 INFO : one: Copied (new) 2024/12/13 01:32:15 DEBUG : Waiting for deletions to finish 2024/12/13 01:32:16 INFO : three.txt.bak: Deleted 2024/12/13 01:32:17 INFO : three.txt: Moved (server-side) to: three.txt.bak 2024/12/13 01:32:17 INFO : three.txt: Moved into backup dir 2024/12/13 01:32:21 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" 2024/12/13 01:32:21 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k" 2024/12/13 01:32:22 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "sk91qgsqfn0r271r2ehsaoc20c" 2024/12/13 01:32:22 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "qltcak2uaegtmcoa8vijdppbp8" 2024/12/13 01:32:22 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "qltcak2uaegtmcoa8vijdppbp8" 2024/12/13 01:32:22 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "sk91qgsqfn0r271r2ehsaoc20c" --- PASS: TestSyncBackupDirWithSuffix (27.91s) === RUN TestSyncBackupDirWithSuffixKeepExtension run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-nuguwer9fuxa'", Local "Local file system at /tmp/rclone588269293", Modify Window "1ms" 2024/12/13 01:32:25 DEBUG : dst/one: md5 = 74e05b8fe3295c24c5614de541a4f48a OK 2024/12/13 01:32:27 DEBUG : dst/two: md5 = 15c0b40474db0a2d03a38fad7bddc523 OK 2024/12/13 01:32:28 DEBUG : dst/three.txt: md5 = d57b5deb8a56d2c275d19eb932e24387 OK 2024/12/13 01:32:29 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-nuguwer9fuxa/dst" 2024/12/13 01:32:29 DEBUG : Creating backend with remote "TestDrive:crypt/sinc28mqh1lj92nob4gqgdh328leac69b1ffmoeuv12ubd3d6640/31u3jie661vd5p8j7rtc3hgbh0" 2024/12/13 01:32:30 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-nuguwer9fuxa/backup" 2024/12/13 01:32:30 DEBUG : Creating backend with remote "TestDrive:crypt/sinc28mqh1lj92nob4gqgdh328leac69b1ffmoeuv12ubd3d6640/1nrff024r7pq65ecp72fc28jb0" 2024/12/13 01:32:32 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-nuguwer9fuxa/dst': Waiting for checks to finish 2024/12/13 01:32:32 DEBUG : one: Sizes differ (src 4 vs dst 3) 2024/12/13 01:32:32 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2024/12/13 01:32:32 DEBUG : two: Unchanged skipping 2024/12/13 01:32:34 INFO : one: Moved (server-side) to: one-2019-01-01 2024/12/13 01:32:34 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-nuguwer9fuxa/dst': Waiting for transfers to finish 2024/12/13 01:32:35 DEBUG : one: md5 = 7af50d92eff3ae579e3101e70d1b1258 OK 2024/12/13 01:32:35 INFO : one: Copied (new) 2024/12/13 01:32:35 DEBUG : Waiting for deletions to finish 2024/12/13 01:32:36 INFO : three.txt: Moved (server-side) to: three-2019-01-01.txt 2024/12/13 01:32:36 INFO : three.txt: Moved into backup dir 2024/12/13 01:32:38 DEBUG : dst/three.txt: md5 = fc739469906a34e96e472325ae257cad OK 2024/12/13 01:32:39 DEBUG : one: Sizes differ (src 5 vs dst 4) 2024/12/13 01:32:39 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2024/12/13 01:32:39 DEBUG : two: Unchanged skipping 2024/12/13 01:32:39 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-nuguwer9fuxa/dst': Waiting for checks to finish 2024/12/13 01:32:40 INFO : one-2019-01-01: Deleted 2024/12/13 01:32:41 INFO : one: Moved (server-side) to: one-2019-01-01 2024/12/13 01:32:41 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-nuguwer9fuxa/dst': Waiting for transfers to finish 2024/12/13 01:32:42 DEBUG : one: md5 = 7b8d0a20666652c6b5c7dd9ca372525e OK 2024/12/13 01:32:42 INFO : one: Copied (new) 2024/12/13 01:32:42 DEBUG : Waiting for deletions to finish 2024/12/13 01:32:43 INFO : three-2019-01-01.txt: Deleted 2024/12/13 01:32:44 INFO : three.txt: Moved (server-side) to: three-2019-01-01.txt 2024/12/13 01:32:44 INFO : three.txt: Moved into backup dir 2024/12/13 01:32:48 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" 2024/12/13 01:32:48 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k" 2024/12/13 01:32:49 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "qtq2f6qq4lgpsmj88vb7147qje3prudmtfdtr2342fth58vo9a50" 2024/12/13 01:32:49 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "jcjl1bv3ep0v8kt35lqql1co90" 2024/12/13 01:32:49 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "qtq2f6qq4lgpsmj88vb7147qje3prudmtfdtr2342fth58vo9a50" 2024/12/13 01:32:49 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "jcjl1bv3ep0v8kt35lqql1co90" --- PASS: TestSyncBackupDirWithSuffixKeepExtension (27.18s) === RUN TestSyncBackupDirSuffixOnly run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-nuguwer9fuxa'", Local "Local file system at /tmp/rclone588269293", Modify Window "1ms" 2024/12/13 01:32:52 DEBUG : dst/one: md5 = b595d25d085b82b1e165c235592d5e88 OK 2024/12/13 01:32:54 DEBUG : dst/two: md5 = efe9b61edbeebc1067e587899aec2a0c OK 2024/12/13 01:32:56 DEBUG : dst/three.txt: md5 = 17b9adaf7a33eec2eb78b62187b81e63 OK 2024/12/13 01:32:56 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-nuguwer9fuxa/dst" 2024/12/13 01:32:56 DEBUG : Creating backend with remote "TestDrive:crypt/sinc28mqh1lj92nob4gqgdh328leac69b1ffmoeuv12ubd3d6640/31u3jie661vd5p8j7rtc3hgbh0" 2024/12/13 01:32:57 DEBUG : one: Sizes differ (src 4 vs dst 3) 2024/12/13 01:32:57 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2024/12/13 01:32:57 DEBUG : two: Unchanged skipping 2024/12/13 01:32:57 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-nuguwer9fuxa/dst': Waiting for checks to finish 2024/12/13 01:32:58 INFO : one: Moved (server-side) to: one.bak 2024/12/13 01:32:58 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-nuguwer9fuxa/dst': Waiting for transfers to finish 2024/12/13 01:33:00 DEBUG : one: md5 = 8a066af93ad6a3ecf51aee0a4010225f OK 2024/12/13 01:33:00 INFO : one: Copied (new) 2024/12/13 01:33:00 DEBUG : Waiting for deletions to finish 2024/12/13 01:33:01 INFO : three.txt: Moved (server-side) to: three.txt.bak 2024/12/13 01:33:01 INFO : three.txt: Moved into backup dir 2024/12/13 01:33:03 DEBUG : dst/three.txt: md5 = 55a6a82ecd00fd3a94d905db11773d38 OK 2024/12/13 01:33:04 DEBUG : one.bak: Excluded (Path Filter) 2024/12/13 01:33:04 DEBUG : one.bak: Excluded 2024/12/13 01:33:04 DEBUG : three.txt.bak: Excluded (Path Filter) 2024/12/13 01:33:04 DEBUG : three.txt.bak: Excluded 2024/12/13 01:33:04 DEBUG : one: Sizes differ (src 5 vs dst 4) 2024/12/13 01:33:04 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-nuguwer9fuxa/dst': Waiting for checks to finish 2024/12/13 01:33:04 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2024/12/13 01:33:04 DEBUG : two: Unchanged skipping 2024/12/13 01:33:05 INFO : one.bak: Deleted 2024/12/13 01:33:05 INFO : one: Moved (server-side) to: one.bak 2024/12/13 01:33:05 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-nuguwer9fuxa/dst': Waiting for transfers to finish 2024/12/13 01:33:07 DEBUG : one: md5 = b69621d84cbd77ee1d11f7f78366ca65 OK 2024/12/13 01:33:07 INFO : one: Copied (new) 2024/12/13 01:33:07 DEBUG : Waiting for deletions to finish 2024/12/13 01:33:08 INFO : three.txt.bak: Deleted 2024/12/13 01:33:09 INFO : three.txt: Moved (server-side) to: three.txt.bak 2024/12/13 01:33:09 INFO : three.txt: Moved into backup dir 2024/12/13 01:33:12 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" 2024/12/13 01:33:12 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "sk91qgsqfn0r271r2ehsaoc20c" 2024/12/13 01:33:12 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "qltcak2uaegtmcoa8vijdppbp8" 2024/12/13 01:33:12 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "qltcak2uaegtmcoa8vijdppbp8" 2024/12/13 01:33:12 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "sk91qgsqfn0r271r2ehsaoc20c" 2024/12/13 01:33:12 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k" --- PASS: TestSyncBackupDirSuffixOnly (23.49s) === RUN TestSyncSuffix run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-nuguwer9fuxa'", Local "Local file system at /tmp/rclone588269293", Modify Window "1ms" 2024/12/13 01:33:16 DEBUG : dst/one: md5 = 573a028ccae7ab6ddb41f7e7be641d96 OK 2024/12/13 01:33:18 DEBUG : dst/two: md5 = bedf0a563bcb334fe501d526911634db OK 2024/12/13 01:33:19 DEBUG : dst/three.txt: md5 = 89b0bb38bd56b6b72f0e33ce200417c1 OK 2024/12/13 01:33:20 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-nuguwer9fuxa/dst" 2024/12/13 01:33:20 DEBUG : Creating backend with remote "TestDrive:crypt/sinc28mqh1lj92nob4gqgdh328leac69b1ffmoeuv12ubd3d6640/31u3jie661vd5p8j7rtc3hgbh0" 2024/12/13 01:33:21 DEBUG : one: Sizes differ (src 4 vs dst 3) 2024/12/13 01:33:22 INFO : one: Moved (server-side) to: one.bak 2024/12/13 01:33:24 DEBUG : one: md5 = 539149ceab3a9791e27d05b1c1bd8f80 OK 2024/12/13 01:33:24 INFO : one: Copied (new) 2024/12/13 01:33:24 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2024/12/13 01:33:24 DEBUG : two: Unchanged skipping 2024/12/13 01:33:24 DEBUG : three.txt: Sizes differ (src 6 vs dst 5) 2024/12/13 01:33:25 INFO : three.txt: Moved (server-side) to: three.txt.bak 2024/12/13 01:33:26 DEBUG : three.txt: md5 = 447729afbd9409179f7f4954e99426f1 OK 2024/12/13 01:33:26 INFO : three.txt: Copied (new) 2024/12/13 01:33:28 DEBUG : one: Sizes differ (src 5 vs dst 4) 2024/12/13 01:33:29 INFO : one.bak: Deleted 2024/12/13 01:33:29 INFO : one: Moved (server-side) to: one.bak 2024/12/13 01:33:31 DEBUG : one: md5 = 7c470af3163f8d9bad9dcf54e82088fb OK 2024/12/13 01:33:31 INFO : one: Copied (new) 2024/12/13 01:33:31 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2024/12/13 01:33:31 DEBUG : two: Unchanged skipping 2024/12/13 01:33:32 DEBUG : three.txt: Sizes differ (src 19 vs dst 6) 2024/12/13 01:33:32 INFO : three.txt.bak: Deleted 2024/12/13 01:33:33 INFO : three.txt: Moved (server-side) to: three.txt.bak 2024/12/13 01:33:35 DEBUG : three.txt: md5 = a99d52baa0aef85a589ae00e47f7d74d OK 2024/12/13 01:33:35 INFO : three.txt: Copied (new) 2024/12/13 01:33:39 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "tr2hj63d80ftlmvm6a952snjcc" 2024/12/13 01:33:39 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" 2024/12/13 01:33:39 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "qltcak2uaegtmcoa8vijdppbp8" 2024/12/13 01:33:39 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "sk91qgsqfn0r271r2ehsaoc20c" 2024/12/13 01:33:39 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k" 2024/12/13 01:33:39 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "qltcak2uaegtmcoa8vijdppbp8" 2024/12/13 01:33:39 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "sk91qgsqfn0r271r2ehsaoc20c" --- PASS: TestSyncSuffix (26.57s) === RUN TestSyncSuffixKeepExtension run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-nuguwer9fuxa'", Local "Local file system at /tmp/rclone588269293", Modify Window "1ms" 2024/12/13 01:33:43 DEBUG : dst/one: md5 = 88fb23b404202e6105506b94ea69cd81 OK 2024/12/13 01:33:44 DEBUG : dst/two: md5 = 7bcad76f95a411100f9f7cf12a6ea2f9 OK 2024/12/13 01:33:46 DEBUG : dst/three.txt: md5 = 77864efef6994da5b4677588ad412370 OK 2024/12/13 01:33:47 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-nuguwer9fuxa/dst" 2024/12/13 01:33:47 DEBUG : Creating backend with remote "TestDrive:crypt/sinc28mqh1lj92nob4gqgdh328leac69b1ffmoeuv12ubd3d6640/31u3jie661vd5p8j7rtc3hgbh0" 2024/12/13 01:33:48 DEBUG : one: Sizes differ (src 4 vs dst 3) 2024/12/13 01:33:49 INFO : one: Moved (server-side) to: one-2019-01-01 2024/12/13 01:33:50 DEBUG : one: md5 = cb2c51bc20891ac5f3bfcc5b8d9c69c3 OK 2024/12/13 01:33:50 INFO : one: Copied (new) 2024/12/13 01:33:51 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2024/12/13 01:33:51 DEBUG : two: Unchanged skipping 2024/12/13 01:33:51 DEBUG : three.txt: Sizes differ (src 6 vs dst 5) 2024/12/13 01:33:52 INFO : three.txt: Moved (server-side) to: three-2019-01-01.txt 2024/12/13 01:33:54 DEBUG : three.txt: md5 = 4004dd217cd326d54b2ef852c60e3081 OK 2024/12/13 01:33:54 INFO : three.txt: Copied (new) 2024/12/13 01:33:55 DEBUG : one: Sizes differ (src 5 vs dst 4) 2024/12/13 01:33:56 INFO : one-2019-01-01: Deleted 2024/12/13 01:33:56 INFO : one: Moved (server-side) to: one-2019-01-01 2024/12/13 01:33:58 DEBUG : one: md5 = 03bb0758e44ec7529112815db0076b94 OK 2024/12/13 01:33:58 INFO : one: Copied (new) 2024/12/13 01:33:58 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2024/12/13 01:33:58 DEBUG : two: Unchanged skipping 2024/12/13 01:33:59 DEBUG : three.txt: Sizes differ (src 19 vs dst 6) 2024/12/13 01:34:00 INFO : three-2019-01-01.txt: Deleted 2024/12/13 01:34:00 INFO : three.txt: Moved (server-side) to: three-2019-01-01.txt 2024/12/13 01:34:02 DEBUG : three.txt: md5 = 03caed356e34381d32cb700fa79e71c4 OK 2024/12/13 01:34:02 INFO : three.txt: Copied (new) 2024/12/13 01:34:06 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" 2024/12/13 01:34:06 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "tr2hj63d80ftlmvm6a952snjcc" 2024/12/13 01:34:06 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "jcjl1bv3ep0v8kt35lqql1co90" 2024/12/13 01:34:06 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "jcjl1bv3ep0v8kt35lqql1co90" 2024/12/13 01:34:06 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "qtq2f6qq4lgpsmj88vb7147qje3prudmtfdtr2342fth58vo9a50" 2024/12/13 01:34:06 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k" 2024/12/13 01:34:06 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "qtq2f6qq4lgpsmj88vb7147qje3prudmtfdtr2342fth58vo9a50" --- PASS: TestSyncSuffixKeepExtension (27.36s) === RUN TestSyncUTFNorm run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-nuguwer9fuxa'", Local "Local file system at /tmp/rclone588269293", Modify Window "1ms" 2024/12/13 01:34:09 DEBUG : Testêé: md5 = e4b6f006407ccbaa11bdc75d1d93f636 OK 2024/12/13 01:34:09 DEBUG : Testêé: Sizes differ (src 14 vs dst 18) 2024/12/13 01:34:09 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-nuguwer9fuxa': Waiting for checks to finish 2024/12/13 01:34:09 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-nuguwer9fuxa': Waiting for transfers to finish 2024/12/13 01:34:11 DEBUG : Testêé: md5 = 572cd21dc13a5d68a55edd9eb6c73996 OK 2024/12/13 01:34:11 INFO : Testêé: Copied (replaced existing) to: Testêé 2024/12/13 01:34:11 DEBUG : Waiting for deletions to finish --- PASS: TestSyncUTFNorm (4.78s) === RUN TestSyncImmutable run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-nuguwer9fuxa'", Local "Local file system at /tmp/rclone588269293", Modify Window "1ms" 2024/12/13 01:34:12 DEBUG : existing: Need to transfer - File not found at Destination 2024/12/13 01:34:12 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-nuguwer9fuxa': Waiting for checks to finish 2024/12/13 01:34:12 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-nuguwer9fuxa': Waiting for transfers to finish 2024/12/13 01:34:14 DEBUG : existing: md5 = 512b11a2c8281a0b7f5b7a2875590361 OK 2024/12/13 01:34:14 INFO : existing: Copied (new) 2024/12/13 01:34:14 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-nuguwer9fuxa'", Local "Local file system at /tmp/rclone588269293", Modify Window "1ms" 2024/12/13 01:34:15 DEBUG : existing: Sizes differ (src 8 vs dst 6) 2024/12/13 01:34:15 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-nuguwer9fuxa': Waiting for checks to finish 2024/12/13 01:34:15 ERROR : existing: Source and destination exist but do not match: immutable file modified 2024/12/13 01:34:15 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-nuguwer9fuxa': Waiting for transfers to finish 2024/12/13 01:34:15 ERROR : Encrypted drive 'TestCryptDrive:rclone-test-nuguwer9fuxa': not deleting files as there were IO errors 2024/12/13 01:34:15 ERROR : Encrypted drive 'TestCryptDrive:rclone-test-nuguwer9fuxa': not deleting directories as there were IO errors run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-nuguwer9fuxa'", Local "Local file system at /tmp/rclone588269293", Modify Window "1ms" --- PASS: TestSyncImmutable (5.36s) === RUN TestSyncIgnoreCase run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-nuguwer9fuxa'", Local "Local file system at /tmp/rclone588269293", Modify Window "1ms" 2024/12/13 01:34:19 DEBUG : EXISTING: md5 = d5216db9b9397ac8c820fc2e1ae1ac75 OK 2024/12/13 01:34:19 DEBUG : existing: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2024/12/13 01:34:19 DEBUG : existing: Unchanged skipping 2024/12/13 01:34:19 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-nuguwer9fuxa': Waiting for checks to finish 2024/12/13 01:34:19 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-nuguwer9fuxa': Waiting for transfers to finish 2024/12/13 01:34:19 DEBUG : Waiting for deletions to finish 2024/12/13 01:34:19 INFO : There was nothing to transfer --- PASS: TestSyncIgnoreCase (3.45s) === RUN TestFixCase run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-nuguwer9fuxa'", Local "Local file system at /tmp/rclone588269293", Modify Window "1ms" sync_test.go:2635: Skipping test as local or remote are case-sensitive --- SKIP: TestFixCase (0.47s) === RUN TestMaxTransfer === RUN TestMaxTransfer/Hard run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-nuguwer9fuxa'", Local "Local file system at /tmp/rclone588269293", 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-nuguwer9fuxa'", Local "Local file system at /tmp/rclone588269293", 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-nuguwer9fuxa'", Local "Local file system at /tmp/rclone588269293", Modify Window "1ms" sync_test.go:2674: This test only runs on local --- PASS: TestMaxTransfer (1.47s) --- SKIP: TestMaxTransfer/Hard (0.51s) --- SKIP: TestMaxTransfer/Soft (0.46s) --- SKIP: TestMaxTransfer/Cautious (0.49s) === RUN TestSyncConcurrentDelete run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-nuguwer9fuxa'", Local "Local file system at /tmp/rclone588269293", Modify Window "1ms" 2024/12/13 01:34:24 DEBUG : both0: md5 = 3c728ea272be60e70139d7cc36790f91 OK 2024/12/13 01:34:26 DEBUG : only0: md5 = 54d8b4a05f1f775fbf59ac280141077d OK 2024/12/13 01:34:28 DEBUG : both1: md5 = b403bb7e15817f9620149b0f2b3f1362 OK 2024/12/13 01:34:29 DEBUG : only1: md5 = 47be96de1eb255e07080d422bd6f1575 OK 2024/12/13 01:34:31 DEBUG : both2: md5 = 35dfabffdc27bd874a1a723975c23766 OK 2024/12/13 01:34:33 DEBUG : only2: md5 = 4cdffa3541b9493eda7ce87556c37bce OK 2024/12/13 01:34:34 DEBUG : both3: md5 = 215d859229fb3f219e7027241f9313f1 OK 2024/12/13 01:34:36 DEBUG : only3: md5 = 506df6ea5e50eed06665f010c9129739 OK 2024/12/13 01:34:38 DEBUG : both4: md5 = bb39f13942d744e49fe66e37d8648ee2 OK 2024/12/13 01:34:39 DEBUG : only4: md5 = 4eb76b7d64a512796d00a8084ec5f061 OK 2024/12/13 01:34:41 DEBUG : both5: md5 = 6e491063412c7e03d018919778df193f OK 2024/12/13 01:34:42 DEBUG : only5: md5 = ddd2876a81aeeeab78109df1dc9a1823 OK 2024/12/13 01:34:44 DEBUG : both6: md5 = beba67d96855b14d6a5c5079045afc36 OK 2024/12/13 01:34:46 DEBUG : only6: md5 = 75bf42d1a3d58cf453a80d8c5c21fe10 OK 2024/12/13 01:34:47 DEBUG : both7: md5 = 7396f3b349867d33b4e3bea0480fd97e OK 2024/12/13 01:34:49 DEBUG : only7: md5 = 64109f34cc8a1ee88f32c584523f98da OK 2024/12/13 01:34:51 DEBUG : both8: md5 = 1ef9ca8a10b5ad1ab08f8dd1240da24c OK 2024/12/13 01:34:53 DEBUG : only8: md5 = 37d7fc2956226769b6c8f7cfd42dfcc4 OK 2024/12/13 01:34:55 DEBUG : both9: md5 = 86a29b0066808c134ed4a804884cd328 OK 2024/12/13 01:34:58 DEBUG : only9: md5 = 40e7a1adbfe070995de86cfec6bd7cf8 OK 2024/12/13 01:34:59 DEBUG : both10: md5 = a85d8b84ea5107874935052d87b700c9 OK 2024/12/13 01:35:01 DEBUG : only10: md5 = b7d4b53e3e31e3de6a2d8beeac65f825 OK 2024/12/13 01:35:03 DEBUG : both11: md5 = 013ecc3ea1dd88007a8805ae657333fc OK 2024/12/13 01:35:05 DEBUG : only11: md5 = a41b6c2b4ce1ee5550895f8873a2940a OK 2024/12/13 01:35:07 DEBUG : both12: md5 = 7011888bef2702ab39888e0bb84904b0 OK 2024/12/13 01:35:08 DEBUG : only12: md5 = d2bc502cd344038940f2109669797c46 OK 2024/12/13 01:35:10 DEBUG : both13: md5 = 983ebf66da5d76810ef93c5bb7ffc81d OK 2024/12/13 01:35:12 DEBUG : only13: md5 = 5a0bfe61e42104b7958683fc0310c02b OK 2024/12/13 01:35:14 DEBUG : both14: md5 = ce7034f7810308793736f6d49645f62e OK 2024/12/13 01:35:15 DEBUG : only14: md5 = 127dea44c1bbb25e4045ddabb5fbaf6d OK 2024/12/13 01:35:17 DEBUG : both15: md5 = 924a59f42fd122c26e6fa6108ca518c8 OK 2024/12/13 01:35:18 DEBUG : only15: md5 = aaaa09110f793d31b9deb247cb8d3303 OK 2024/12/13 01:35:20 DEBUG : both16: md5 = fceb42fbf5613dc31f94bca420758edc OK 2024/12/13 01:35:22 DEBUG : only16: md5 = 94bb16f3c79c53ca0a6255dff9d4b763 OK 2024/12/13 01:35:24 DEBUG : both17: md5 = e1e92941d4bf536ecfb6835faee6b1d5 OK 2024/12/13 01:35:26 DEBUG : only17: md5 = 929ad60526106007bc08add522e12be1 OK 2024/12/13 01:35:27 DEBUG : both18: md5 = ce6228d0c6259e0c1d710ddb3bfd238b OK 2024/12/13 01:35:29 DEBUG : only18: md5 = f684b9d924fcf789de4d726622be9667 OK 2024/12/13 01:35:31 DEBUG : both19: md5 = 32a3ce778210f8108fdab3c0b24809a6 OK 2024/12/13 01:35:32 DEBUG : only19: md5 = ad2809686ad8c3afb2c8f6f22b00e656 OK 2024/12/13 01:35:33 DEBUG : both0: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2024/12/13 01:35:33 DEBUG : both1: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2024/12/13 01:35:33 DEBUG : both11: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2024/12/13 01:35:33 DEBUG : both10: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2024/12/13 01:35:33 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-nuguwer9fuxa': Waiting for checks to finish 2024/12/13 01:35:33 DEBUG : both0: Unchanged skipping 2024/12/13 01:35:33 DEBUG : both12: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2024/12/13 01:35:33 DEBUG : both12: Unchanged skipping 2024/12/13 01:35:33 DEBUG : both13: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2024/12/13 01:35:33 DEBUG : both13: Unchanged skipping 2024/12/13 01:35:33 DEBUG : both14: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2024/12/13 01:35:33 DEBUG : both14: Unchanged skipping 2024/12/13 01:35:33 DEBUG : both15: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2024/12/13 01:35:33 DEBUG : both15: Unchanged skipping 2024/12/13 01:35:33 DEBUG : both16: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2024/12/13 01:35:33 DEBUG : both16: Unchanged skipping 2024/12/13 01:35:33 DEBUG : both17: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2024/12/13 01:35:33 DEBUG : both17: Unchanged skipping 2024/12/13 01:35:33 DEBUG : both18: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2024/12/13 01:35:33 DEBUG : both18: Unchanged skipping 2024/12/13 01:35:33 DEBUG : both19: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2024/12/13 01:35:33 DEBUG : both1: Unchanged skipping 2024/12/13 01:35:33 DEBUG : both2: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2024/12/13 01:35:33 DEBUG : both11: Unchanged skipping 2024/12/13 01:35:33 DEBUG : both3: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2024/12/13 01:35:33 DEBUG : both10: Unchanged skipping 2024/12/13 01:35:33 DEBUG : both4: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2024/12/13 01:35:33 DEBUG : both19: Unchanged skipping 2024/12/13 01:35:33 DEBUG : both5: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2024/12/13 01:35:33 DEBUG : both2: Unchanged skipping 2024/12/13 01:35:33 DEBUG : both6: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2024/12/13 01:35:33 DEBUG : both3: Unchanged skipping 2024/12/13 01:35:33 DEBUG : both7: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2024/12/13 01:35:33 DEBUG : both4: Unchanged skipping 2024/12/13 01:35:33 DEBUG : both8: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2024/12/13 01:35:33 DEBUG : both5: Unchanged skipping 2024/12/13 01:35:33 DEBUG : both9: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2024/12/13 01:35:33 DEBUG : both6: Unchanged skipping 2024/12/13 01:35:33 DEBUG : both7: Unchanged skipping 2024/12/13 01:35:33 DEBUG : both8: Unchanged skipping 2024/12/13 01:35:33 DEBUG : both9: Unchanged skipping 2024/12/13 01:35:33 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-nuguwer9fuxa': Waiting for transfers to finish 2024/12/13 01:35:33 DEBUG : Waiting for deletions to finish 2024/12/13 01:35:34 INFO : only1: Deleted 2024/12/13 01:35:34 INFO : only19: Deleted 2024/12/13 01:35:34 INFO : only18: Deleted 2024/12/13 01:35:34 INFO : only10: Deleted 2024/12/13 01:35:34 INFO : only12: Deleted 2024/12/13 01:35:34 INFO : only15: Deleted 2024/12/13 01:35:34 INFO : only7: Deleted 2024/12/13 01:35:34 INFO : only16: Deleted 2024/12/13 01:35:34 INFO : only17: Deleted 2024/12/13 01:35:35 INFO : only14: Deleted 2024/12/13 01:35:35 INFO : only0: Deleted 2024/12/13 01:35:35 INFO : only5: Deleted 2024/12/13 01:35:35 INFO : only6: Deleted 2024/12/13 01:35:35 INFO : only8: Deleted 2024/12/13 01:35:35 INFO : only9: Deleted 2024/12/13 01:35:35 INFO : only11: Deleted 2024/12/13 01:35:36 INFO : only2: Deleted 2024/12/13 01:35:36 INFO : only13: Deleted 2024/12/13 01:35:36 INFO : only3: Deleted 2024/12/13 01:35:36 INFO : only4: Deleted 2024/12/13 01:35:36 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-nuguwer9fuxa'", Local "Local file system at /tmp/rclone588269293", Modify Window "1ms" --- PASS: TestSyncConcurrentDelete (85.81s) === RUN TestSyncConcurrentTruncate run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-nuguwer9fuxa'", Local "Local file system at /tmp/rclone588269293", Modify Window "1ms" 2024/12/13 01:35:50 DEBUG : both0: md5 = 286840494fd4fbe6841d909acbead88e OK 2024/12/13 01:35:52 DEBUG : only0: md5 = bb7d118ea8914979c724da11bf49b67f OK 2024/12/13 01:35:53 DEBUG : both1: md5 = 9d84c3bf2ed17e285fdfb58e50e5e297 OK 2024/12/13 01:35:55 DEBUG : only1: md5 = eb9dc0080e4b281383cc3811c33da45f OK 2024/12/13 01:35:56 DEBUG : both2: md5 = 26c13fdc571870e880bd06a2bdb470d6 OK 2024/12/13 01:35:58 DEBUG : only2: md5 = 44b806793d156036768ab62d69ecc125 OK 2024/12/13 01:36:00 DEBUG : both3: md5 = 6d40cae9c266a6c49b0739cdf2f19803 OK 2024/12/13 01:36:02 DEBUG : only3: md5 = 2c7829685b8e4ad9bc14df567c01da76 OK 2024/12/13 01:36:03 DEBUG : both4: md5 = e8bf06bce994e97e63555e3c6d8865e9 OK 2024/12/13 01:36:05 DEBUG : only4: md5 = 2e9c9c0efae2d14608a4122a94359791 OK 2024/12/13 01:36:07 DEBUG : both5: md5 = a21e2bfecf91fbd674f06730d33daaa0 OK 2024/12/13 01:36:08 DEBUG : only5: md5 = 2d72d3d017e3d80d67032921e0c0ecc9 OK 2024/12/13 01:36:10 DEBUG : both6: md5 = e12624277c4df7a2ed288a057da63b0e OK 2024/12/13 01:36:12 DEBUG : only6: md5 = fd16f49e3f333017da18e9f15f8504e5 OK 2024/12/13 01:36:14 DEBUG : both7: md5 = 72a2d78c8cf97a709019fba6bdc556ea OK 2024/12/13 01:36:15 DEBUG : only7: md5 = ff5257bb2d3a612cbd742ebf6751c5d7 OK 2024/12/13 01:36:17 DEBUG : both8: md5 = 4da7a0edfedc521885c28bdfca7759fb OK 2024/12/13 01:36:19 DEBUG : only8: md5 = 7941de67ced4975377abfc0a851a2283 OK 2024/12/13 01:36:20 DEBUG : both9: md5 = b5aeb630293536580efd5001bd63b837 OK 2024/12/13 01:36:22 DEBUG : only9: md5 = 5185bce399561206608e165cff987d3d OK 2024/12/13 01:36:24 DEBUG : both10: md5 = c9bad314add8fd84f3c49765621d19c6 OK 2024/12/13 01:36:26 DEBUG : only10: md5 = d7e56976c7e592af1866f5bc98acebc8 OK 2024/12/13 01:36:27 DEBUG : both11: md5 = 8f9bcbf92564ae90aa7aefa7b642c203 OK 2024/12/13 01:36:29 DEBUG : only11: md5 = 6698a35ae3590893b7ea8b6c834829e8 OK 2024/12/13 01:36:31 DEBUG : both12: md5 = 2430ada9a0d03dc552c9fe3dd7fc3ed5 OK 2024/12/13 01:36:32 DEBUG : only12: md5 = ab6efc0bc1471e3171fdd6befac041c5 OK 2024/12/13 01:36:34 DEBUG : both13: md5 = 38c800fdaf28a9fdf871ff24de52cec7 OK 2024/12/13 01:36:36 DEBUG : only13: md5 = 5b0826df4c823bf52cf0bf9b4cfee521 OK 2024/12/13 01:36:38 DEBUG : both14: md5 = e503f5517a1ef9c3a212f6fd2cb2f038 OK 2024/12/13 01:36:39 DEBUG : only14: md5 = dfa930cf0580bba7efa8bf3d88e2cf3f OK 2024/12/13 01:36:41 DEBUG : both15: md5 = b16e9c12178b3422e10d01e7fa8096b9 OK 2024/12/13 01:36:43 DEBUG : only15: md5 = 38d89b32e54d4392d35ca4d8f8b0588d OK 2024/12/13 01:36:45 DEBUG : both16: md5 = e7a2fcce593820b11c328e5bcaa75cee OK 2024/12/13 01:36:47 DEBUG : only16: md5 = 74b6587174fa8539204d288a15535c1e OK 2024/12/13 01:36:48 DEBUG : both17: md5 = 7840d2da9c324095dd39107cc7f6206b OK 2024/12/13 01:36:50 DEBUG : only17: md5 = b86a102a07eb44eb810d37ff2f09ae35 OK 2024/12/13 01:36:51 DEBUG : both18: md5 = 2f32298d24ad0a5f21e5634f0dc40a3f OK 2024/12/13 01:36:53 DEBUG : only18: md5 = 8598fd8db1cbaccc68f6ad939ea3ca33 OK 2024/12/13 01:36:55 DEBUG : both19: md5 = 4cd78854ffcf153d6d14c43a3f5b1aa8 OK 2024/12/13 01:36:57 DEBUG : only19: md5 = 7eaa9de396c4e9c1145e877ef42428ee OK 2024/12/13 01:36:57 DEBUG : both1: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2024/12/13 01:36:57 DEBUG : both10: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2024/12/13 01:36:57 DEBUG : both11: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2024/12/13 01:36:57 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-nuguwer9fuxa': Waiting for checks to finish 2024/12/13 01:36:57 DEBUG : both0: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2024/12/13 01:36:57 DEBUG : both1: Unchanged skipping 2024/12/13 01:36:57 DEBUG : both12: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2024/12/13 01:36:57 DEBUG : both12: Unchanged skipping 2024/12/13 01:36:57 DEBUG : both13: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2024/12/13 01:36:57 DEBUG : both13: Unchanged skipping 2024/12/13 01:36:57 DEBUG : both14: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2024/12/13 01:36:57 DEBUG : both14: Unchanged skipping 2024/12/13 01:36:57 DEBUG : both15: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2024/12/13 01:36:57 DEBUG : both10: Unchanged skipping 2024/12/13 01:36:57 DEBUG : both16: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2024/12/13 01:36:57 DEBUG : both16: Unchanged skipping 2024/12/13 01:36:57 DEBUG : both17: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2024/12/13 01:36:57 DEBUG : both17: Unchanged skipping 2024/12/13 01:36:57 DEBUG : both18: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2024/12/13 01:36:57 DEBUG : both18: Unchanged skipping 2024/12/13 01:36:57 DEBUG : both19: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2024/12/13 01:36:57 DEBUG : both19: Unchanged skipping 2024/12/13 01:36:57 DEBUG : both2: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2024/12/13 01:36:57 DEBUG : both2: Unchanged skipping 2024/12/13 01:36:57 DEBUG : both3: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2024/12/13 01:36:57 DEBUG : both11: Unchanged skipping 2024/12/13 01:36:57 DEBUG : both4: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2024/12/13 01:36:57 DEBUG : both4: Unchanged skipping 2024/12/13 01:36:57 DEBUG : both5: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2024/12/13 01:36:57 DEBUG : both0: Unchanged skipping 2024/12/13 01:36:57 DEBUG : both6: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2024/12/13 01:36:57 DEBUG : both15: Unchanged skipping 2024/12/13 01:36:57 DEBUG : both7: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2024/12/13 01:36:57 DEBUG : both3: Unchanged skipping 2024/12/13 01:36:57 DEBUG : both8: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2024/12/13 01:36:57 DEBUG : both8: Unchanged skipping 2024/12/13 01:36:57 DEBUG : both9: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2024/12/13 01:36:57 DEBUG : both9: Unchanged skipping 2024/12/13 01:36:57 DEBUG : only0: Sizes differ (src 0 vs dst 6) 2024/12/13 01:36:57 DEBUG : only1: Sizes differ (src 0 vs dst 6) 2024/12/13 01:36:57 DEBUG : only10: Sizes differ (src 0 vs dst 6) 2024/12/13 01:36:57 DEBUG : only11: Sizes differ (src 0 vs dst 6) 2024/12/13 01:36:57 DEBUG : only12: Sizes differ (src 0 vs dst 6) 2024/12/13 01:36:57 DEBUG : only13: Sizes differ (src 0 vs dst 6) 2024/12/13 01:36:57 DEBUG : only14: Sizes differ (src 0 vs dst 6) 2024/12/13 01:36:57 DEBUG : only15: Sizes differ (src 0 vs dst 6) 2024/12/13 01:36:57 DEBUG : only16: Sizes differ (src 0 vs dst 6) 2024/12/13 01:36:57 DEBUG : only17: Sizes differ (src 0 vs dst 6) 2024/12/13 01:36:57 DEBUG : only18: Sizes differ (src 0 vs dst 6) 2024/12/13 01:36:57 DEBUG : only19: Sizes differ (src 0 vs dst 6) 2024/12/13 01:36:57 DEBUG : only2: Sizes differ (src 0 vs dst 6) 2024/12/13 01:36:57 DEBUG : only3: Sizes differ (src 0 vs dst 6) 2024/12/13 01:36:57 DEBUG : only4: Sizes differ (src 0 vs dst 6) 2024/12/13 01:36:57 DEBUG : only5: Sizes differ (src 0 vs dst 6) 2024/12/13 01:36:57 DEBUG : only6: Sizes differ (src 0 vs dst 6) 2024/12/13 01:36:57 DEBUG : only7: Sizes differ (src 0 vs dst 6) 2024/12/13 01:36:57 DEBUG : only8: Sizes differ (src 0 vs dst 6) 2024/12/13 01:36:57 DEBUG : only9: Sizes differ (src 0 vs dst 6) 2024/12/13 01:36:57 DEBUG : both5: Unchanged skipping 2024/12/13 01:36:57 DEBUG : both6: Unchanged skipping 2024/12/13 01:36:57 DEBUG : both7: Unchanged skipping 2024/12/13 01:36:57 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-nuguwer9fuxa': Waiting for transfers to finish 2024/12/13 01:36:58 DEBUG : only0: md5 = b8d04ed87d3f56d5961a5772d056d94c OK 2024/12/13 01:36:58 INFO : only0: Copied (replaced existing) 2024/12/13 01:36:58 DEBUG : only11: md5 = df5c3d3b41fd0b0f7f1ba23bf9a175e6 OK 2024/12/13 01:36:58 INFO : only11: Copied (replaced existing) 2024/12/13 01:36:58 DEBUG : only10: md5 = 0d54655088085952059f923a228c8a2f OK 2024/12/13 01:36:58 INFO : only10: Copied (replaced existing) 2024/12/13 01:36:58 DEBUG : only1: md5 = 31c29cf94d5b4da712959e55e6adef94 OK 2024/12/13 01:36:58 INFO : only1: Copied (replaced existing) 2024/12/13 01:37:00 DEBUG : only12: md5 = c49c856a8a612a760aa3cbe5b4d5be69 OK 2024/12/13 01:37:00 INFO : only12: Copied (replaced existing) 2024/12/13 01:37:00 DEBUG : only14: md5 = 6361fdd5c73046ad93d521f912359c6d OK 2024/12/13 01:37:00 INFO : only14: Copied (replaced existing) 2024/12/13 01:37:00 DEBUG : only15: md5 = 445bba4755a06070b0899c72c9102a35 OK 2024/12/13 01:37:00 INFO : only15: Copied (replaced existing) 2024/12/13 01:37:00 DEBUG : only13: md5 = 6ed25c4da2b7269948c894292dcb0a15 OK 2024/12/13 01:37:00 INFO : only13: Copied (replaced existing) 2024/12/13 01:37:01 DEBUG : only17: md5 = fd9b1d506ed31ceee5ae50f074ac99d0 OK 2024/12/13 01:37:01 INFO : only17: Copied (replaced existing) 2024/12/13 01:37:01 DEBUG : only16: md5 = f8659beae989b9f718c8fda4e4dc5bc5 OK 2024/12/13 01:37:01 INFO : only16: Copied (replaced existing) 2024/12/13 01:37:01 DEBUG : only19: md5 = 4333cf1c9cf6e72c485ad58163f54710 OK 2024/12/13 01:37:01 INFO : only19: Copied (replaced existing) 2024/12/13 01:37:01 DEBUG : only18: md5 = 84981c42bdce98e4b2dfcbd7def69fdb OK 2024/12/13 01:37:01 INFO : only18: Copied (replaced existing) 2024/12/13 01:37:02 DEBUG : only2: md5 = 1a9d88f9a462c39035600df0772877ff OK 2024/12/13 01:37:02 INFO : only2: Copied (replaced existing) 2024/12/13 01:37:02 DEBUG : only3: md5 = 66fdce3e383f3da6244b4f30b6dc7ed4 OK 2024/12/13 01:37:02 INFO : only3: Copied (replaced existing) 2024/12/13 01:37:02 DEBUG : only4: md5 = 1dd5f114ee2ddb6880a4b8eac88ae01f OK 2024/12/13 01:37:02 INFO : only4: Copied (replaced existing) 2024/12/13 01:37:02 DEBUG : only5: md5 = 0599a0559823cbaef91316fa0bef5dbc OK 2024/12/13 01:37:02 INFO : only5: Copied (replaced existing) 2024/12/13 01:37:03 DEBUG : only6: md5 = 33beb40ac62c4182f33c138f8216df0b OK 2024/12/13 01:37:03 INFO : only6: Copied (replaced existing) 2024/12/13 01:37:04 DEBUG : only7: md5 = 3f2e5a39540020010aac1be85b59fa26 OK 2024/12/13 01:37:04 INFO : only7: Copied (replaced existing) 2024/12/13 01:37:04 DEBUG : only8: md5 = a1384d106db6ad152b9b83833134fc3a OK 2024/12/13 01:37:04 INFO : only8: Copied (replaced existing) 2024/12/13 01:37:04 DEBUG : only9: md5 = 8094dc82dc5048329ce6001250bf13cf OK 2024/12/13 01:37:04 INFO : only9: Copied (replaced existing) 2024/12/13 01:37:04 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-nuguwer9fuxa'", Local "Local file system at /tmp/rclone588269293", Modify Window "1ms" --- PASS: TestSyncConcurrentTruncate (99.42s) === RUN TestNothingToTransferWithEmptyDirs run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-nuguwer9fuxa'", Local "Local file system at /tmp/rclone588269293", Modify Window "1ms" 2024/12/13 01:37:28 INFO : sub dir: Set directory modification time (using DirSetModTime) 2024/12/13 01:37:28 DEBUG : sub dir: Making directory with metadata 2024/12/13 01:37:29 INFO : sub dir: Made directory with metadata (mtime=2011-12-30T12:59:59Z) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-nuguwer9fuxa'", Local "Local file system at /tmp/rclone588269293", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-nuguwer9fuxa'", Local "Local file system at /tmp/rclone588269293", Modify Window "1ms" 2024/12/13 01:37:49 INFO : sub dir2: Set directory modification time (using DirSetModTime) 2024/12/13 01:37:50 INFO : sub dir2: Set directory modification time (using DirSetModTime) 2024/12/13 01:37:50 INFO : sub dirEmpty/sub dirEmpty2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2024/12/13 01:37:50 INFO : sub dirEmpty: Set directory modification time (using DirSetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-nuguwer9fuxa'", Local "Local file system at /tmp/rclone588269293", Modify Window "1ms" 2024/12/13 01:38:04 DEBUG : gcsdkq814sbtppue42dpsbg8ug: Rmdir: contains trashed file: "sjuo65gk5q3r1199jselk9k9o0" 2024/12/13 01:38:05 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/37qp6d1gohacv723ij3brofbu8/i24n0ln37pa2hv8pctddeuh73o: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" 2024/12/13 01:38:05 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/37qp6d1gohacv723ij3brofbu8: Rmdir: contains trashed file: "i24n0ln37pa2hv8pctddeuh73o" 2024/12/13 01:38:06 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "37qp6d1gohacv723ij3brofbu8" 2024/12/13 01:38:07 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak" 2024/12/13 01:38:08 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak" 2024/12/13 01:38:09 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak" 2024/12/13 01:38:10 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak" 2024/12/13 01:38:11 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/4r13oncfa2rsrr82oqhsqv24ns: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" 2024/12/13 01:38:12 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc: Rmdir: contains trashed file: "4r13oncfa2rsrr82oqhsqv24ns" 2024/12/13 01:38:12 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak" 2024/12/13 01:38:13 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestNothingToTransferWithEmptyDirs (47.12s) === RUN TestNothingToTransferWithoutEmptyDirs run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-nuguwer9fuxa'", Local "Local file system at /tmp/rclone588269293", Modify Window "1ms" 2024/12/13 01:38:15 INFO : sub dir: Set directory modification time (using DirSetModTime) 2024/12/13 01:38:15 DEBUG : sub dir: Making directory with metadata 2024/12/13 01:38:16 INFO : sub dir: Made directory with metadata (mtime=2011-12-30T12:59:59Z) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-nuguwer9fuxa'", Local "Local file system at /tmp/rclone588269293", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-nuguwer9fuxa'", Local "Local file system at /tmp/rclone588269293", Modify Window "1ms" 2024/12/13 01:38:41 INFO : sub dir2: Set directory modification time (using DirSetModTime) 2024/12/13 01:38:42 INFO : sub dir2: Set directory modification time (using DirSetModTime) 2024/12/13 01:38:42 INFO : sub dirEmpty/sub dirEmpty2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2024/12/13 01:38:42 INFO : sub dirEmpty: Set directory modification time (using DirSetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-nuguwer9fuxa'", Local "Local file system at /tmp/rclone588269293", Modify Window "1ms" 2024/12/13 01:38:54 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/37qp6d1gohacv723ij3brofbu8/i24n0ln37pa2hv8pctddeuh73o: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" 2024/12/13 01:38:55 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/37qp6d1gohacv723ij3brofbu8: Rmdir: contains trashed file: "i24n0ln37pa2hv8pctddeuh73o" 2024/12/13 01:38:55 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "37qp6d1gohacv723ij3brofbu8" 2024/12/13 01:38:56 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak" 2024/12/13 01:38:57 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak" 2024/12/13 01:38:58 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak" 2024/12/13 01:38:59 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak" 2024/12/13 01:39:00 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/4r13oncfa2rsrr82oqhsqv24ns: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" 2024/12/13 01:39:01 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc: Rmdir: contains trashed file: "4r13oncfa2rsrr82oqhsqv24ns" 2024/12/13 01:39:01 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak" 2024/12/13 01:39:02 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestNothingToTransferWithoutEmptyDirs (48.78s) PASS 2024/12/13 01:39:04 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-nuguwer9fuxa': Purge remote "./sync.test -test.v -test.timeout 1h0m0s -remote TestCryptDrive: -verbose" - Finished OK in 17m55.098122116s (try 1/5)