"./sync.test -test.v -test.timeout 1h0m0s -remote TestCryptDrive: -verbose" - Starting (try 1/5) 2025/02/13 21:30:38 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-zegicih0cola" 2025/02/13 21:30:38 DEBUG : Using config file from "/home/rclone/.rclone.conf" 2025/02/13 21:30:38 DEBUG : Creating backend with remote "TestDrive:crypt/acm2bl29gbtuhl9b1qh375055t9lo9mvu40inkr1thg9c16mrlrg" 2025/02/13 21:30:40 DEBUG : Creating backend with remote "/tmp/rclone3758268997" === RUN TestPipe --- PASS: TestPipe (0.00s) === RUN TestPipeConcurrent --- PASS: TestPipeConcurrent (0.02s) === RUN TestPipeOrderBy === RUN TestPipeOrderBy/#00 === RUN TestPipeOrderBy/size === RUN TestPipeOrderBy/name === RUN TestPipeOrderBy/modtime === RUN TestPipeOrderBy/size,ascending === RUN TestPipeOrderBy/name,asc === RUN TestPipeOrderBy/modtime,ascending === RUN TestPipeOrderBy/size,descending === RUN TestPipeOrderBy/name,desc === RUN TestPipeOrderBy/modtime,descending === RUN TestPipeOrderBy/size,mixed,50 === RUN TestPipeOrderBy/size,mixed,51 --- PASS: TestPipeOrderBy (0.00s) --- PASS: TestPipeOrderBy/#00 (0.00s) --- PASS: TestPipeOrderBy/size (0.00s) --- PASS: TestPipeOrderBy/name (0.00s) --- PASS: TestPipeOrderBy/modtime (0.00s) --- PASS: TestPipeOrderBy/size,ascending (0.00s) --- PASS: TestPipeOrderBy/name,asc (0.00s) --- PASS: TestPipeOrderBy/modtime,ascending (0.00s) --- PASS: TestPipeOrderBy/size,descending (0.00s) --- PASS: TestPipeOrderBy/name,desc (0.00s) --- PASS: TestPipeOrderBy/modtime,descending (0.00s) --- PASS: TestPipeOrderBy/size,mixed,50 (0.00s) --- PASS: TestPipeOrderBy/size,mixed,51 (0.00s) === RUN TestNewLess === RUN TestNewLess/blankOK === RUN TestNewLess/tooManyParts === RUN TestNewLess/tooManyParts2 === RUN TestNewLess/badMixed === RUN TestNewLess/unknownComparison === RUN TestNewLess/unknownSortDirection === RUN TestNewLess/size === RUN TestNewLess/name === RUN TestNewLess/modtime === RUN TestNewLess/size,ascending === RUN TestNewLess/name,asc === RUN TestNewLess/modtime,ascending === RUN TestNewLess/size,descending === RUN TestNewLess/name,desc === RUN TestNewLess/modtime,descending === RUN TestNewLess/modtime,mixed === RUN TestNewLess/modtime,mixed,30 --- PASS: TestNewLess (0.00s) --- PASS: TestNewLess/blankOK (0.00s) --- PASS: TestNewLess/tooManyParts (0.00s) --- PASS: TestNewLess/tooManyParts2 (0.00s) --- PASS: TestNewLess/badMixed (0.00s) --- PASS: TestNewLess/unknownComparison (0.00s) --- PASS: TestNewLess/unknownSortDirection (0.00s) --- PASS: TestNewLess/size (0.00s) --- PASS: TestNewLess/name (0.00s) --- PASS: TestNewLess/modtime (0.00s) --- PASS: TestNewLess/size,ascending (0.00s) --- PASS: TestNewLess/name,asc (0.00s) --- PASS: TestNewLess/modtime,ascending (0.00s) --- PASS: TestNewLess/size,descending (0.00s) --- PASS: TestNewLess/name,desc (0.00s) --- PASS: TestNewLess/modtime,descending (0.00s) --- PASS: TestNewLess/modtime,mixed (0.00s) --- PASS: TestNewLess/modtime,mixed,30 (0.00s) === RUN TestRcCopy rc_test.go:16: Skipping test on non local remote --- SKIP: TestRcCopy (0.00s) === RUN TestRcMove rc_test.go:16: Skipping test on non local remote --- SKIP: TestRcMove (0.00s) === RUN TestRcSync rc_test.go:16: Skipping test on non local remote --- SKIP: TestRcSync (0.00s) === RUN TestCopyWithDryRun run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zegicih0cola'", Local "Local file system at /tmp/rclone3758268997", Modify Window "1ms" 2025/02/13 21:30:41 DEBUG : Added delayed dir = "sub dir", newDst= 2025/02/13 21:30:41 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2025/02/13 21:30:41 NOTICE: sub dir/hello world: Skipped copy as --dry-run is set (size 11) 2025/02/13 21:30:41 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zegicih0cola': Waiting for checks to finish 2025/02/13 21:30:41 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zegicih0cola': Waiting for transfers to finish 2025/02/13 21:30:41 NOTICE: sub dir: Skipped set directory modification time as --dry-run is set run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zegicih0cola'", Local "Local file system at /tmp/rclone3758268997", Modify Window "1ms" --- PASS: TestCopyWithDryRun (2.39s) === RUN TestCopy run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zegicih0cola'", Local "Local file system at /tmp/rclone3758268997", Modify Window "1ms" 2025/02/13 21:30:42 INFO : sub dir: Set directory modification time (using DirSetModTime) 2025/02/13 21:30:42 DEBUG : Added delayed dir = "sub dir", newDst= 2025/02/13 21:30:42 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2025/02/13 21:30:42 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zegicih0cola': Waiting for checks to finish 2025/02/13 21:30:42 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zegicih0cola': Waiting for transfers to finish 2025/02/13 21:30:44 DEBUG : sub dir/hello world: md5 = d062f1d6ec72dee794f78cca8bc8223c OK 2025/02/13 21:30:44 INFO : sub dir/hello world: Copied (new) 2025/02/13 21:30:45 INFO : sub dir: Set directory modification time (using DirSetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zegicih0cola'", Local "Local file system at /tmp/rclone3758268997", Modify Window "1ms" 2025/02/13 21:30:47 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestCopy (5.80s) === RUN TestCopyMetadata run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zegicih0cola'", Local "Local file system at /tmp/rclone3758268997", Modify Window "1ms" 2025/02/13 21:30:48 DEBUG : metadata sub dir: Making directory with metadata 2025/02/13 21:30:48 INFO : metadata sub dir: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2025/02/13 21:30:48 DEBUG : empty metadata sub dir: Making directory with metadata 2025/02/13 21:30:48 INFO : empty metadata sub dir: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2025/02/13 21:30:48 DEBUG : Local file system at /tmp/rclone3758268997: File to upload is small (21 bytes), uploading instead of streaming 2025/02/13 21:30:48 DEBUG : metadata sub dir/hello metadata world: md5 = baa7a013449dbba2b1ed02b5cfb4e1a2 OK 2025/02/13 21:30:48 DEBUG : metadata sub dir/hello metadata world: Size and md5 of src and dst objects identical 2025/02/13 21:30:48 INFO : metadata sub dir: Set directory modification time (using DirSetModTime) 2025/02/13 21:30:48 DEBUG : Google drive root 'crypt/acm2bl29gbtuhl9b1qh375055t9lo9mvu40inkr1thg9c16mrlrg': Skipping btime metadata as can't update it on an existing file: 2025-02-13T21:30:48.291877174Z 2025/02/13 21:30:49 INFO : empty metadata sub dir: Updated directory metadata 2025/02/13 21:30:49 DEBUG : Google drive root 'crypt/acm2bl29gbtuhl9b1qh375055t9lo9mvu40inkr1thg9c16mrlrg': Skipping btime metadata as can't update it on an existing file: 2025-02-13T21:30:48.287877197Z 2025/02/13 21:30:50 INFO : metadata sub dir: Updated directory metadata 2025/02/13 21:30:50 DEBUG : metadata sub dir/hello metadata world: Need to transfer - File not found at Destination 2025/02/13 21:30:50 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zegicih0cola': Waiting for checks to finish 2025/02/13 21:30:50 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zegicih0cola': Waiting for transfers to finish 2025/02/13 21:30:51 DEBUG : metadata sub dir/hello metadata world: md5 = 9906cff51535a031f21aebae9bab9f4a OK 2025/02/13 21:30:51 INFO : metadata sub dir/hello metadata world: Copied (new) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zegicih0cola'", Local "Local file system at /tmp/rclone3758268997", Modify Window "1ms" 2025/02/13 21:30:54 DEBUG : fg45q1rm3kh00nmmkk4m6ihmrcnel1p7551kqhjr9bk2gtd2gbf0: Rmdir: contains trashed file: "dmuvulfij81f693ur0f1vvbvq9v6iscp56daas3m51n9li5e3470" --- PASS: TestCopyMetadata (7.68s) === RUN TestCopyMetadataNoEmptyDirs run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zegicih0cola'", Local "Local file system at /tmp/rclone3758268997", Modify Window "1ms" 2025/02/13 21:30:55 DEBUG : metadata sub dir: Making directory with metadata 2025/02/13 21:30:55 INFO : metadata sub dir: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2025/02/13 21:30:55 DEBUG : empty metadata sub dir: Making directory with metadata 2025/02/13 21:30:55 INFO : empty metadata sub dir: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2025/02/13 21:30:55 DEBUG : Local file system at /tmp/rclone3758268997: File to upload is small (21 bytes), uploading instead of streaming 2025/02/13 21:30:55 DEBUG : metadata sub dir/hello metadata world: md5 = baa7a013449dbba2b1ed02b5cfb4e1a2 OK 2025/02/13 21:30:55 DEBUG : metadata sub dir/hello metadata world: Size and md5 of src and dst objects identical 2025/02/13 21:30:55 INFO : metadata sub dir: Set directory modification time (using DirSetModTime) 2025/02/13 21:30:56 DEBUG : Added delayed dir = "empty metadata sub dir", newDst= 2025/02/13 21:30:56 DEBUG : Added delayed dir = "metadata sub dir", newDst= 2025/02/13 21:30:56 DEBUG : metadata sub dir/hello metadata world: Need to transfer - File not found at Destination 2025/02/13 21:30:56 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zegicih0cola': Waiting for checks to finish 2025/02/13 21:30:56 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zegicih0cola': Waiting for transfers to finish 2025/02/13 21:30:58 DEBUG : metadata sub dir/hello metadata world: md5 = e3b4f1a3b158213e4fa2145448b24620 OK 2025/02/13 21:30:58 INFO : metadata sub dir/hello metadata world: Copied (new) 2025/02/13 21:30:58 DEBUG : Google drive root 'crypt/acm2bl29gbtuhl9b1qh375055t9lo9mvu40inkr1thg9c16mrlrg': Skipping btime metadata as can't update it on an existing file: 2025-02-13T21:30:55.971832515Z 2025/02/13 21:30:58 INFO : metadata sub dir: Updated directory metadata run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zegicih0cola'", Local "Local file system at /tmp/rclone3758268997", Modify Window "1ms" 2025/02/13 21:31:02 DEBUG : fg45q1rm3kh00nmmkk4m6ihmrcnel1p7551kqhjr9bk2gtd2gbf0: Rmdir: contains trashed file: "dmuvulfij81f693ur0f1vvbvq9v6iscp56daas3m51n9li5e3470" --- PASS: TestCopyMetadataNoEmptyDirs (7.37s) === RUN TestCopyMissingDirectory run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zegicih0cola'", Local "Local file system at /tmp/rclone3758268997", Modify Window "1ms" 2025/02/13 21:31:03 DEBUG : Creating backend with remote "/non-existing" 2025/02/13 21:31:03 ERROR : Local file system at /non-existing: error reading source root directory: directory not found 2025/02/13 21:31:03 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zegicih0cola': Waiting for checks to finish 2025/02/13 21:31:03 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zegicih0cola': Waiting for transfers to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zegicih0cola'", Local "Local file system at /tmp/rclone3758268997", Modify Window "1ms" --- PASS: TestCopyMissingDirectory (1.20s) === RUN TestCopyNoTraverse run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zegicih0cola'", Local "Local file system at /tmp/rclone3758268997", Modify Window "1ms" 2025/02/13 21:31:04 DEBUG : Added delayed dir = "sub dir", newDst= 2025/02/13 21:31:04 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2025/02/13 21:31:04 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zegicih0cola': Waiting for checks to finish 2025/02/13 21:31:04 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zegicih0cola': Waiting for transfers to finish 2025/02/13 21:31:06 DEBUG : sub dir/hello world: md5 = 759e259a28c5fc1389921756d7d02d5a OK 2025/02/13 21:31:06 INFO : sub dir/hello world: Copied (new) 2025/02/13 21:31:07 INFO : sub dir: Set directory modification time (using DirSetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zegicih0cola'", Local "Local file system at /tmp/rclone3758268997", Modify Window "1ms" 2025/02/13 21:31:09 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestCopyNoTraverse (5.86s) === RUN TestCopyCheckFirst run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zegicih0cola'", Local "Local file system at /tmp/rclone3758268997", Modify Window "1ms" 2025/02/13 21:31:10 INFO : Encrypted drive 'TestCryptDrive:rclone-test-zegicih0cola': Running all checks before starting transfers 2025/02/13 21:31:10 DEBUG : Added delayed dir = "sub dir", newDst= 2025/02/13 21:31:10 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2025/02/13 21:31:10 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zegicih0cola': Waiting for checks to finish 2025/02/13 21:31:10 INFO : Encrypted drive 'TestCryptDrive:rclone-test-zegicih0cola': Checks finished, now starting transfers 2025/02/13 21:31:10 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zegicih0cola': Waiting for transfers to finish 2025/02/13 21:31:12 DEBUG : sub dir/hello world: md5 = 023772c4398bc1a6ba1e7f1f99ec42d9 OK 2025/02/13 21:31:12 INFO : sub dir/hello world: Copied (new) 2025/02/13 21:31:13 INFO : sub dir: Set directory modification time (using DirSetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zegicih0cola'", Local "Local file system at /tmp/rclone3758268997", Modify Window "1ms" 2025/02/13 21:31:15 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestCopyCheckFirst (6.04s) === RUN TestSyncNoTraverse run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zegicih0cola'", Local "Local file system at /tmp/rclone3758268997", Modify Window "1ms" 2025/02/13 21:31:16 ERROR : Ignoring --no-traverse with sync 2025/02/13 21:31:16 DEBUG : Added delayed dir = "sub dir", newDst= 2025/02/13 21:31:16 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2025/02/13 21:31:16 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zegicih0cola': Waiting for checks to finish 2025/02/13 21:31:16 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zegicih0cola': Waiting for transfers to finish 2025/02/13 21:31:18 DEBUG : sub dir/hello world: md5 = 82b9d32b4a71883b71f4920f1c70e805 OK 2025/02/13 21:31:18 INFO : sub dir/hello world: Copied (new) 2025/02/13 21:31:18 DEBUG : Waiting for deletions to finish 2025/02/13 21:31:19 INFO : sub dir: Set directory modification time (using DirSetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zegicih0cola'", Local "Local file system at /tmp/rclone3758268997", Modify Window "1ms" 2025/02/13 21:31:20 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestSyncNoTraverse (5.49s) === RUN TestCopyWithDepth run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zegicih0cola'", Local "Local file system at /tmp/rclone3758268997", Modify Window "1ms" 2025/02/13 21:31:22 DEBUG : hello world2: Need to transfer - File not found at Destination 2025/02/13 21:31:22 DEBUG : Added delayed dir = "sub dir", newDst= 2025/02/13 21:31:22 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zegicih0cola': Waiting for checks to finish 2025/02/13 21:31:22 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zegicih0cola': Waiting for transfers to finish 2025/02/13 21:31:23 DEBUG : hello world2: md5 = 05864120d45cc8a6772c2cafcb001354 OK 2025/02/13 21:31:23 INFO : hello world2: Copied (new) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zegicih0cola'", Local "Local file system at /tmp/rclone3758268997", Modify Window "1ms" --- PASS: TestCopyWithDepth (3.11s) === RUN TestCopyWithFilesFrom run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zegicih0cola'", Local "Local file system at /tmp/rclone3758268997", Modify Window "1ms" 2025/02/13 21:31:25 DEBUG : potato2: Need to transfer - File not found at Destination 2025/02/13 21:31:25 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zegicih0cola': Waiting for checks to finish 2025/02/13 21:31:25 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zegicih0cola': Waiting for transfers to finish 2025/02/13 21:31:26 DEBUG : potato2: md5 = 58c61a6bb1e67f87aa52fbfde009b2c4 OK 2025/02/13 21:31:26 INFO : potato2: Copied (new) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zegicih0cola'", Local "Local file system at /tmp/rclone3758268997", Modify Window "1ms" --- PASS: TestCopyWithFilesFrom (3.38s) === RUN TestCopyWithFilesFromAndNoTraverse run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zegicih0cola'", Local "Local file system at /tmp/rclone3758268997", Modify Window "1ms" 2025/02/13 21:31:28 DEBUG : potato2: Need to transfer - File not found at Destination 2025/02/13 21:31:28 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zegicih0cola': Waiting for checks to finish 2025/02/13 21:31:28 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zegicih0cola': Waiting for transfers to finish 2025/02/13 21:31:30 DEBUG : potato2: md5 = 0b20a4fd6729615da1fb4924893ae055 OK 2025/02/13 21:31:30 INFO : potato2: Copied (new) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zegicih0cola'", Local "Local file system at /tmp/rclone3758268997", Modify Window "1ms" --- PASS: TestCopyWithFilesFromAndNoTraverse (3.17s) === RUN TestCopyEmptyDirectories run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zegicih0cola'", Local "Local file system at /tmp/rclone3758268997", Modify Window "1ms" 2025/02/13 21:31:31 DEBUG : sub dir2/sub sub dir2: Making directory with metadata 2025/02/13 21:31:31 INFO : sub dir2/sub sub dir2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2025/02/13 21:31:31 INFO : sub dir2: Set directory modification time (using DirSetModTime) 2025/02/13 21:31:31 INFO : sub dir: Set directory modification time (using DirSetModTime) 2025/02/13 21:31:31 DEBUG : sub dir: Making directory with metadata 2025/02/13 21:31:32 INFO : sub dir: Made directory with metadata (mtime=2001-02-03T04:05:06.499999999Z) 2025/02/13 21:31:32 DEBUG : sub dir2: Making directory with metadata 2025/02/13 21:31:33 INFO : sub dir2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2025/02/13 21:31:33 DEBUG : sub dir2/sub sub dir2: Making directory with metadata 2025/02/13 21:31:33 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2025/02/13 21:31:34 INFO : sub dir2/sub sub dir2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2025/02/13 21:31:34 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zegicih0cola': Waiting for checks to finish 2025/02/13 21:31:34 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zegicih0cola': Waiting for transfers to finish 2025/02/13 21:31:35 DEBUG : sub dir/hello world: md5 = 8dd598fca19c70a309b15a1a911c6742 OK 2025/02/13 21:31:35 INFO : sub dir/hello world: Copied (new) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zegicih0cola'", Local "Local file system at /tmp/rclone3758268997", Modify Window "1ms" 2025/02/13 21:31:39 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc: Rmdir: contains trashed file: "cv6a9uf28ngrajena8kt5ijjn0" 2025/02/13 21:31:39 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestCopyEmptyDirectories (9.42s) === RUN TestCopyNoEmptyDirectories run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zegicih0cola'", Local "Local file system at /tmp/rclone3758268997", Modify Window "1ms" 2025/02/13 21:31:41 INFO : sub dir2: Making directory 2025/02/13 21:31:41 DEBUG : sub dir2/sub sub dir2: Making directory with metadata 2025/02/13 21:31:41 INFO : sub dir2/sub sub dir2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2025/02/13 21:31:41 DEBUG : Added delayed dir = "sub dir", newDst= 2025/02/13 21:31:41 DEBUG : Added delayed dir = "sub dir2", newDst= 2025/02/13 21:31:41 DEBUG : Added delayed dir = "sub dir2/sub sub dir2", newDst= 2025/02/13 21:31:41 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2025/02/13 21:31:41 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zegicih0cola': Waiting for checks to finish 2025/02/13 21:31:41 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zegicih0cola': Waiting for transfers to finish 2025/02/13 21:31:43 DEBUG : sub dir/hello world: md5 = 53512cbfcbbd2615ba526a911b3ecbaa OK 2025/02/13 21:31:43 INFO : sub dir/hello world: Copied (new) 2025/02/13 21:31:44 INFO : sub dir: Set directory modification time (using DirSetModTime) 2025/02/13 21:31:45 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestCopyNoEmptyDirectories (5.39s) === RUN TestMoveEmptyDirectories run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zegicih0cola'", Local "Local file system at /tmp/rclone3758268997", Modify Window "1ms" 2025/02/13 21:31:46 DEBUG : sub dir2: Making directory with metadata 2025/02/13 21:31:46 INFO : sub dir2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2025/02/13 21:31:46 DEBUG : sub dir: Making directory with metadata 2025/02/13 21:31:47 INFO : sub dir: Made directory with metadata (mtime=2025-02-13T21:31:46.407536691Z) 2025/02/13 21:31:47 DEBUG : sub dir2: Making directory with metadata 2025/02/13 21:31:48 INFO : sub dir2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2025/02/13 21:31:48 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2025/02/13 21:31:48 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zegicih0cola': Waiting for checks to finish 2025/02/13 21:31:48 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zegicih0cola': Waiting for transfers to finish 2025/02/13 21:31:49 DEBUG : sub dir/hello world: md5 = 20f35f0e7f9519abeb8d5f6c3ceabfdc OK 2025/02/13 21:31:49 INFO : sub dir/hello world: Copied (new) 2025/02/13 21:31:49 INFO : sub dir/hello world: Deleted run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zegicih0cola'", Local "Local file system at /tmp/rclone3758268997", Modify Window "1ms" 2025/02/13 21:31:52 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestMoveEmptyDirectories (7.35s) === RUN TestSyncNoUpdateDirModtime run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zegicih0cola'", Local "Local file system at /tmp/rclone3758268997", Modify Window "1ms" 2025/02/13 21:31:53 DEBUG : sub dir no update dir modtime: Making directory with metadata 2025/02/13 21:31:53 INFO : sub dir no update dir modtime: Made directory with metadata (mtime=2001-02-03T04:05:06.499999999Z) 2025/02/13 21:31:55 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zegicih0cola': Waiting for checks to finish 2025/02/13 21:31:55 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zegicih0cola': Waiting for transfers to finish 2025/02/13 21:31:55 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zegicih0cola'", Local "Local file system at /tmp/rclone3758268997", Modify Window "1ms" --- PASS: TestSyncNoUpdateDirModtime (4.30s) === RUN TestMoveNoEmptyDirectories run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zegicih0cola'", Local "Local file system at /tmp/rclone3758268997", Modify Window "1ms" 2025/02/13 21:31:58 INFO : sub dir2: Making directory 2025/02/13 21:31:58 DEBUG : Added delayed dir = "sub dir", newDst= 2025/02/13 21:31:58 DEBUG : Added delayed dir = "sub dir2", newDst= 2025/02/13 21:31:58 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2025/02/13 21:31:58 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zegicih0cola': Waiting for checks to finish 2025/02/13 21:31:58 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zegicih0cola': Waiting for transfers to finish 2025/02/13 21:32:00 DEBUG : sub dir/hello world: md5 = d72cec3dfb8b27526c9b6dc5e85f3bc4 OK 2025/02/13 21:32:00 INFO : sub dir/hello world: Copied (new) 2025/02/13 21:32:00 INFO : sub dir/hello world: Deleted 2025/02/13 21:32:00 INFO : sub dir: Set directory modification time (using DirSetModTime) 2025/02/13 21:32:02 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestMoveNoEmptyDirectories (5.28s) === RUN TestSyncEmptyDirectories run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zegicih0cola'", Local "Local file system at /tmp/rclone3758268997", Modify Window "1ms" 2025/02/13 21:32:03 DEBUG : sub dir2: Making directory with metadata 2025/02/13 21:32:03 INFO : sub dir2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2025/02/13 21:32:03 INFO : sub dir: Set directory modification time (using DirSetModTime) 2025/02/13 21:32:03 DEBUG : sub dir: Making directory with metadata 2025/02/13 21:32:04 INFO : sub dir: Made directory with metadata (mtime=2001-02-03T04:05:06.499999999Z) 2025/02/13 21:32:04 DEBUG : sub dir2: Making directory with metadata 2025/02/13 21:32:05 INFO : sub dir2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2025/02/13 21:32:05 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2025/02/13 21:32:05 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zegicih0cola': Waiting for checks to finish 2025/02/13 21:32:05 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zegicih0cola': Waiting for transfers to finish 2025/02/13 21:32:06 DEBUG : sub dir/hello world: md5 = 488fd446a502d3ef675827dc2b1673bd OK 2025/02/13 21:32:06 INFO : sub dir/hello world: Copied (new) 2025/02/13 21:32:06 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zegicih0cola'", Local "Local file system at /tmp/rclone3758268997", Modify Window "1ms" 2025/02/13 21:32:09 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestSyncEmptyDirectories (7.73s) === RUN TestSyncSetDelayedModTimes run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zegicih0cola'", Local "Local file system at /tmp/rclone3758268997", Modify Window "1ms" sync_test.go:507: Backend doesn't have DirModTimeUpdatesOnWrite set --- SKIP: TestSyncSetDelayedModTimes (0.54s) === RUN TestSyncNoEmptyDirectories run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zegicih0cola'", Local "Local file system at /tmp/rclone3758268997", Modify Window "1ms" 2025/02/13 21:32:11 INFO : sub dir2: Making directory 2025/02/13 21:32:11 DEBUG : Added delayed dir = "sub dir", newDst= 2025/02/13 21:32:11 DEBUG : Added delayed dir = "sub dir2", newDst= 2025/02/13 21:32:11 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2025/02/13 21:32:11 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zegicih0cola': Waiting for checks to finish 2025/02/13 21:32:11 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zegicih0cola': Waiting for transfers to finish 2025/02/13 21:32:14 DEBUG : sub dir/hello world: md5 = bcdff019020c23b85b23e7885daa5bfe OK 2025/02/13 21:32:14 INFO : sub dir/hello world: Copied (new) 2025/02/13 21:32:14 DEBUG : Waiting for deletions to finish 2025/02/13 21:32:14 INFO : sub dir: Set directory modification time (using DirSetModTime) 2025/02/13 21:32:16 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestSyncNoEmptyDirectories (5.45s) === RUN TestServerSideCopy run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zegicih0cola'", Local "Local file system at /tmp/rclone3758268997", Modify Window "1ms" 2025/02/13 21:32:19 DEBUG : sub dir/hello world: md5 = e4f9d29e38fb504c9c5ce547b0ef30ab OK 2025/02/13 21:32:19 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-hokomay2zile" 2025/02/13 21:32:19 DEBUG : Creating backend with remote "TestDrive:crypt/isso26hiqu786emnbao5pfiq04le9hdetfmu6l5rfdh66hh4600g" sync_test.go:590: Server side copy (if possible) Encrypted drive 'TestCryptDrive:rclone-test-zegicih0cola' -> Encrypted drive 'TestCryptDrive:rclone-test-hokomay2zile' 2025/02/13 21:32:20 DEBUG : Added delayed dir = "sub dir", newDst= 2025/02/13 21:32:21 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2025/02/13 21:32:21 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hokomay2zile': Waiting for checks to finish 2025/02/13 21:32:21 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hokomay2zile': Waiting for transfers to finish 2025/02/13 21:32:23 INFO : sub dir/hello world: Copied (server-side copy) 2025/02/13 21:32:23 INFO : sub dir: Set directory modification time (using DirSetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zegicih0cola'", Local "Local file system at /tmp/rclone3758268997", Modify Window "1ms" 2025/02/13 21:32:24 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hokomay2zile': Purge remote 2025/02/13 21:32:26 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestServerSideCopy (10.51s) === RUN TestCopyOverSelf run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zegicih0cola'", Local "Local file system at /tmp/rclone3758268997", Modify Window "1ms" 2025/02/13 21:32:29 DEBUG : sub dir/hello world: md5 = e3eb30b6ffcc01c74d3efa618ffd9471 OK 2025/02/13 21:32:30 DEBUG : Added delayed dir = "sub dir", newDst=sub dir 2025/02/13 21:32:30 DEBUG : sub dir/hello world: Sizes differ (src 17 vs dst 11) 2025/02/13 21:32:30 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zegicih0cola': Waiting for checks to finish 2025/02/13 21:32:30 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zegicih0cola': Waiting for transfers to finish 2025/02/13 21:32:32 DEBUG : sub dir/hello world: md5 = c7c257fb6262b1f52f7afd5e99554256 OK 2025/02/13 21:32:32 INFO : sub dir/hello world: Copied (replaced existing) 2025/02/13 21:32:32 INFO : sub dir: Set directory modification time (using SetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zegicih0cola'", Local "Local file system at /tmp/rclone3758268997", Modify Window "1ms" 2025/02/13 21:32:34 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestCopyOverSelf (7.72s) === RUN TestServerSideCopyOverSelf run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zegicih0cola'", Local "Local file system at /tmp/rclone3758268997", Modify Window "1ms" 2025/02/13 21:32:37 DEBUG : sub dir/hello world: md5 = e99ac77ea2ba894c4af12c783399ed5f OK 2025/02/13 21:32:37 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-lehakor0xete" 2025/02/13 21:32:38 DEBUG : Creating backend with remote "TestDrive:crypt/4vcfntr12m58aovudrdfvrpegf7d50ph12lmr8brrpis82ahuuj0" sync_test.go:626: Server side copy (if possible) Encrypted drive 'TestCryptDrive:rclone-test-zegicih0cola' -> Encrypted drive 'TestCryptDrive:rclone-test-lehakor0xete' 2025/02/13 21:32:39 DEBUG : Added delayed dir = "sub dir", newDst= 2025/02/13 21:32:39 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2025/02/13 21:32:39 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-lehakor0xete': Waiting for checks to finish 2025/02/13 21:32:39 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-lehakor0xete': Waiting for transfers to finish 2025/02/13 21:32:41 INFO : sub dir/hello world: Copied (server-side copy) 2025/02/13 21:32:42 INFO : sub dir: Set directory modification time (using DirSetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zegicih0cola'", Local "Local file system at /tmp/rclone3758268997", Modify Window "1ms" 2025/02/13 21:32:44 DEBUG : sub dir/hello world: md5 = c2f44f8544e2a4e91cfbee04b04bce56 OK 2025/02/13 21:32:45 DEBUG : sub dir: Directory modification time the same (differ by 0s, within tolerance 1ms) 2025/02/13 21:32:45 DEBUG : Added delayed dir = "sub dir", newDst=sub dir 2025/02/13 21:32:45 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-lehakor0xete': Waiting for checks to finish 2025/02/13 21:32:45 DEBUG : sub dir/hello world: Sizes differ (src 17 vs dst 11) 2025/02/13 21:32:45 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-lehakor0xete': Waiting for transfers to finish 2025/02/13 21:32:46 INFO : sub dir/hello world: Copied (server-side copy) 2025/02/13 21:32:47 INFO : sub dir: Set directory modification time (using SetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zegicih0cola'", Local "Local file system at /tmp/rclone3758268997", Modify Window "1ms" 2025/02/13 21:32:47 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-lehakor0xete': Purge remote 2025/02/13 21:32:49 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestServerSideCopyOverSelf (15.77s) === RUN TestMoveOverSelf run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zegicih0cola'", Local "Local file system at /tmp/rclone3758268997", Modify Window "1ms" 2025/02/13 21:32:53 DEBUG : sub dir/hello world: md5 = af6132ad8fd3095eb7b89cea5b04ebb9 OK 2025/02/13 21:32:54 DEBUG : Added delayed dir = "sub dir", newDst=sub dir 2025/02/13 21:32:54 DEBUG : sub dir/hello world: Sizes differ (src 17 vs dst 11) 2025/02/13 21:32:54 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zegicih0cola': Waiting for checks to finish 2025/02/13 21:32:54 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zegicih0cola': Waiting for transfers to finish 2025/02/13 21:32:55 DEBUG : sub dir/hello world: md5 = 0a541cdab0ed86a3da25e05fd987abca OK 2025/02/13 21:32:55 INFO : sub dir/hello world: Copied (replaced existing) 2025/02/13 21:32:55 INFO : sub dir/hello world: Deleted 2025/02/13 21:32:55 INFO : sub dir: Set directory modification time (using SetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zegicih0cola'", Local "Local file system at /tmp/rclone3758268997", Modify Window "1ms" 2025/02/13 21:32:57 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestMoveOverSelf (7.51s) === RUN TestServerSideMoveOverSelf run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zegicih0cola'", Local "Local file system at /tmp/rclone3758268997", Modify Window "1ms" 2025/02/13 21:33:00 DEBUG : sub dir/hello world: md5 = 8a1f832f3e7e852242a746e019973495 OK 2025/02/13 21:33:01 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-maxopat7zolo" 2025/02/13 21:33:01 DEBUG : Config file has changed externally - reloading 2025/02/13 21:33:01 DEBUG : Creating backend with remote "TestDrive:crypt/ttujlicbdrj5lfg9bvguva2jk1nls1q71uft52isj0ua6hf83aj0" sync_test.go:671: Server side copy (if possible) Encrypted drive 'TestCryptDrive:rclone-test-zegicih0cola' -> Encrypted drive 'TestCryptDrive:rclone-test-maxopat7zolo' 2025/02/13 21:33:02 DEBUG : Added delayed dir = "sub dir", newDst= 2025/02/13 21:33:02 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2025/02/13 21:33:02 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-maxopat7zolo': Waiting for checks to finish 2025/02/13 21:33:02 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-maxopat7zolo': Waiting for transfers to finish 2025/02/13 21:33:05 INFO : sub dir/hello world: Copied (server-side copy) 2025/02/13 21:33:05 INFO : sub dir: Set directory modification time (using DirSetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zegicih0cola'", Local "Local file system at /tmp/rclone3758268997", Modify Window "1ms" 2025/02/13 21:33:07 DEBUG : sub dir/hello world: md5 = ed6dcb975748e35ccaf7b675c191050c OK 2025/02/13 21:33:08 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-maxopat7zolo': Using server-side directory move 2025/02/13 21:33:08 INFO : Encrypted drive 'TestCryptDrive:rclone-test-maxopat7zolo': Server side directory move failed - fallback to file moves: can't copy directory - destination already exists 2025/02/13 21:33:08 DEBUG : sub dir: Directory modification time the same (differ by 0s, within tolerance 1ms) 2025/02/13 21:33:08 DEBUG : Added delayed dir = "sub dir", newDst=sub dir 2025/02/13 21:33:08 DEBUG : sub dir/hello world: Sizes differ (src 17 vs dst 11) 2025/02/13 21:33:08 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-maxopat7zolo': Waiting for checks to finish 2025/02/13 21:33:08 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-maxopat7zolo': Waiting for transfers to finish 2025/02/13 21:33:09 INFO : sub dir/hello world: Deleted 2025/02/13 21:33:09 INFO : sub dir/hello world: Moved (server-side) 2025/02/13 21:33:10 INFO : sub dir: Set directory modification time (using SetModTime) 2025/02/13 21:33:12 DEBUG : sub dir/hello world: md5 = 4838f30be10ea52e534ae6f9e1d6b27b OK 2025/02/13 21:33:12 DEBUG : testing file moves 2025/02/13 21:33:13 DEBUG : sub dir: Directory modification time the same (differ by 0s, within tolerance 1ms) 2025/02/13 21:33:13 DEBUG : Added delayed dir = "sub dir", newDst=sub dir 2025/02/13 21:33:13 DEBUG : sub dir/hello world: Sizes differ (src 24 vs dst 17) 2025/02/13 21:33:13 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-maxopat7zolo': Waiting for checks to finish 2025/02/13 21:33:13 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-maxopat7zolo': Waiting for transfers to finish 2025/02/13 21:33:13 INFO : sub dir/hello world: Deleted 2025/02/13 21:33:14 INFO : sub dir/hello world: Moved (server-side) 2025/02/13 21:33:14 INFO : sub dir: Set directory modification time (using SetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zegicih0cola'", Local "Local file system at /tmp/rclone3758268997", Modify Window "1ms" 2025/02/13 21:33:15 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-maxopat7zolo': Purge remote --- PASS: TestServerSideMoveOverSelf (20.21s) === RUN TestCopyAfterDelete run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zegicih0cola'", Local "Local file system at /tmp/rclone3758268997", Modify Window "1ms" 2025/02/13 21:33:20 DEBUG : sub dir/hello world: md5 = 8809952306a0dc34532409e4719e4ada OK 2025/02/13 21:33:20 ERROR : : error listing: directory not found 2025/02/13 21:33:21 INFO : Local file system at /tmp/rclone3758268997: Making directory 2025/02/13 21:33:21 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zegicih0cola': Waiting for checks to finish 2025/02/13 21:33:21 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zegicih0cola': Waiting for transfers to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zegicih0cola'", Local "Local file system at /tmp/rclone3758268997", Modify Window "1ms" 2025/02/13 21:33:23 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestCopyAfterDelete (5.68s) === RUN TestCopyRedownload run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zegicih0cola'", Local "Local file system at /tmp/rclone3758268997", Modify Window "1ms" 2025/02/13 21:33:26 DEBUG : sub dir/hello world: md5 = 6b027ced1d988299908d3569100d5ece OK 2025/02/13 21:33:27 DEBUG : Added delayed dir = "sub dir", newDst= 2025/02/13 21:33:27 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2025/02/13 21:33:27 DEBUG : Local file system at /tmp/rclone3758268997: Waiting for checks to finish 2025/02/13 21:33:27 DEBUG : Local file system at /tmp/rclone3758268997: Waiting for transfers to finish 2025/02/13 21:33:28 DEBUG : sub dir/hello world.285f0a30.partial: renamed to: sub dir/hello world 2025/02/13 21:33:28 INFO : sub dir/hello world: Copied (new) 2025/02/13 21:33:28 INFO : sub dir: Set directory modification time (using DirSetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zegicih0cola'", Local "Local file system at /tmp/rclone3758268997", Modify Window "1ms" 2025/02/13 21:33:29 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestCopyRedownload (6.60s) === RUN TestSyncBasedOnCheckSum run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zegicih0cola'", Local "Local file system at /tmp/rclone3758268997", Modify Window "1ms" 2025/02/13 21:33:31 DEBUG : check sum: Need to transfer - File not found at Destination 2025/02/13 21:33:31 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zegicih0cola': Waiting for checks to finish 2025/02/13 21:33:31 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zegicih0cola': Waiting for transfers to finish 2025/02/13 21:33:32 DEBUG : check sum: md5 = 265efe53a763ecb52eaccce83479dc17 OK 2025/02/13 21:33:32 INFO : check sum: Copied (new) 2025/02/13 21:33:32 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zegicih0cola'", Local "Local file system at /tmp/rclone3758268997", Modify Window "1ms" 2025/02/13 21:33:33 NOTICE: Encrypted drive 'TestCryptDrive:rclone-test-zegicih0cola': --checksum is in use but the source and destination have no hashes in common; falling back to --size-only 2025/02/13 21:33:33 DEBUG : check sum: Size of src and dst objects identical 2025/02/13 21:33:33 DEBUG : check sum: Unchanged skipping 2025/02/13 21:33:33 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zegicih0cola': Waiting for checks to finish 2025/02/13 21:33:33 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zegicih0cola': Waiting for transfers to finish 2025/02/13 21:33:33 DEBUG : Waiting for deletions to finish 2025/02/13 21:33:33 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zegicih0cola'", Local "Local file system at /tmp/rclone3758268997", Modify Window "1ms" --- PASS: TestSyncBasedOnCheckSum (4.07s) === RUN TestSyncSizeOnly run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zegicih0cola'", Local "Local file system at /tmp/rclone3758268997", Modify Window "1ms" 2025/02/13 21:33:35 DEBUG : sizeonly: Need to transfer - File not found at Destination 2025/02/13 21:33:35 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zegicih0cola': Waiting for checks to finish 2025/02/13 21:33:35 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zegicih0cola': Waiting for transfers to finish 2025/02/13 21:33:36 DEBUG : sizeonly: md5 = 987a2dadcb23e222c641b55dfe371aac OK 2025/02/13 21:33:36 INFO : sizeonly: Copied (new) 2025/02/13 21:33:36 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zegicih0cola'", Local "Local file system at /tmp/rclone3758268997", Modify Window "1ms" 2025/02/13 21:33:37 DEBUG : sizeonly: Sizes identical 2025/02/13 21:33:37 DEBUG : sizeonly: Unchanged skipping 2025/02/13 21:33:37 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zegicih0cola': Waiting for checks to finish 2025/02/13 21:33:37 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zegicih0cola': Waiting for transfers to finish 2025/02/13 21:33:37 DEBUG : Waiting for deletions to finish 2025/02/13 21:33:37 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zegicih0cola'", Local "Local file system at /tmp/rclone3758268997", Modify Window "1ms" --- PASS: TestSyncSizeOnly (4.16s) === RUN TestSyncIgnoreSize run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zegicih0cola'", Local "Local file system at /tmp/rclone3758268997", Modify Window "1ms" 2025/02/13 21:33:39 DEBUG : ignore-size: Need to transfer - File not found at Destination 2025/02/13 21:33:39 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zegicih0cola': Waiting for checks to finish 2025/02/13 21:33:39 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zegicih0cola': Waiting for transfers to finish 2025/02/13 21:33:40 DEBUG : ignore-size: md5 = b75271ba2b96d8478b7ce85eae376de9 OK 2025/02/13 21:33:40 INFO : ignore-size: Copied (new) 2025/02/13 21:33:40 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zegicih0cola'", Local "Local file system at /tmp/rclone3758268997", Modify Window "1ms" 2025/02/13 21:33:41 DEBUG : ignore-size: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/02/13 21:33:41 DEBUG : ignore-size: Unchanged skipping 2025/02/13 21:33:41 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zegicih0cola': Waiting for checks to finish 2025/02/13 21:33:41 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zegicih0cola': Waiting for transfers to finish 2025/02/13 21:33:41 DEBUG : Waiting for deletions to finish 2025/02/13 21:33:41 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zegicih0cola'", Local "Local file system at /tmp/rclone3758268997", Modify Window "1ms" --- PASS: TestSyncIgnoreSize (4.10s) === RUN TestSyncIgnoreTimes run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zegicih0cola'", Local "Local file system at /tmp/rclone3758268997", Modify Window "1ms" 2025/02/13 21:33:44 DEBUG : existing: md5 = eb1aec813d640e16e8bf2742c2ed39c5 OK 2025/02/13 21:33:45 DEBUG : existing: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/02/13 21:33:45 DEBUG : existing: Unchanged skipping 2025/02/13 21:33:45 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zegicih0cola': Waiting for checks to finish 2025/02/13 21:33:45 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zegicih0cola': Waiting for transfers to finish 2025/02/13 21:33:45 DEBUG : Waiting for deletions to finish 2025/02/13 21:33:45 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zegicih0cola'", Local "Local file system at /tmp/rclone3758268997", Modify Window "1ms" 2025/02/13 21:33:45 DEBUG : existing: Transferring unconditionally as --ignore-times is in use 2025/02/13 21:33:45 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zegicih0cola': Waiting for checks to finish 2025/02/13 21:33:45 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zegicih0cola': Waiting for transfers to finish 2025/02/13 21:33:46 DEBUG : existing: md5 = 2700099f981fb869f280868176577458 OK 2025/02/13 21:33:46 INFO : existing: Copied (replaced existing) 2025/02/13 21:33:46 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zegicih0cola'", Local "Local file system at /tmp/rclone3758268997", Modify Window "1ms" --- PASS: TestSyncIgnoreTimes (5.44s) === RUN TestSyncIgnoreExisting run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zegicih0cola'", Local "Local file system at /tmp/rclone3758268997", Modify Window "1ms" 2025/02/13 21:33:49 DEBUG : existing: Need to transfer - File not found at Destination 2025/02/13 21:33:49 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zegicih0cola': Waiting for checks to finish 2025/02/13 21:33:49 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zegicih0cola': Waiting for transfers to finish 2025/02/13 21:33:50 DEBUG : existing: md5 = 00f4acb87751c0bafef3b25fd9f9f0cc OK 2025/02/13 21:33:50 INFO : existing: Copied (new) 2025/02/13 21:33:50 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zegicih0cola'", Local "Local file system at /tmp/rclone3758268997", Modify Window "1ms" 2025/02/13 21:33:50 DEBUG : existing: Destination exists, skipping 2025/02/13 21:33:50 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zegicih0cola': Waiting for checks to finish 2025/02/13 21:33:50 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zegicih0cola': Waiting for transfers to finish 2025/02/13 21:33:50 DEBUG : Waiting for deletions to finish 2025/02/13 21:33:50 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zegicih0cola'", Local "Local file system at /tmp/rclone3758268997", Modify Window "1ms" --- PASS: TestSyncIgnoreExisting (3.94s) === RUN TestSyncIgnoreErrors run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zegicih0cola'", Local "Local file system at /tmp/rclone3758268997", Modify Window "1ms" 2025/02/13 21:33:54 DEBUG : b/potato: md5 = 1f31653f7ee5dc2615690cef17126169 OK 2025/02/13 21:33:57 DEBUG : c/non empty space: md5 = d25888954d440bb3898db7ec14cc718c OK 2025/02/13 21:33:57 INFO : d: Making directory 2025/02/13 21:33:58 DEBUG : Added delayed dir = "a", newDst= 2025/02/13 21:33:58 DEBUG : Added delayed dir = "c", newDst=c 2025/02/13 21:33:58 DEBUG : a/potato2: Need to transfer - File not found at Destination 2025/02/13 21:33:58 DEBUG : c/non empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/02/13 21:33:58 DEBUG : c/non empty space: Unchanged skipping 2025/02/13 21:33:59 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zegicih0cola': Waiting for checks to finish 2025/02/13 21:33:59 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zegicih0cola': Waiting for transfers to finish 2025/02/13 21:34:00 DEBUG : a/potato2: md5 = 2e89a7f3f235b1a4ffd60f3e2e65c907 OK 2025/02/13 21:34:00 INFO : a/potato2: Copied (new) 2025/02/13 21:34:00 DEBUG : Waiting for deletions to finish 2025/02/13 21:34:01 INFO : b/potato: Deleted 2025/02/13 21:34:01 INFO : a: Set directory modification time (using DirSetModTime) 2025/02/13 21:34:01 INFO : d: Removing directory 2025/02/13 21:34:02 INFO : b: Removing directory 2025/02/13 21:34:02 DEBUG : 32d8ua6196mc1r7qkfog53rkg0: Rmdir: contains trashed file: "2m507n64kafsi59v9q71r281a4" 2025/02/13 21:34:03 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zegicih0cola': deleted 2 directories run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zegicih0cola'", Local "Local file system at /tmp/rclone3758268997", Modify Window "1ms" 2025/02/13 21:34:05 DEBUG : 3i9du405pfogq3ncai6pg7ouio: Rmdir: contains trashed file: "982d3pss7t5pn0il16r2foj31s" 2025/02/13 21:34:05 DEBUG : 2bsvlrk2ne1lfitm6tttcu0qt8: Rmdir: contains trashed file: "89l8renevh3mji1c8r1p7qn6tg" --- PASS: TestSyncIgnoreErrors (14.08s) === RUN TestSyncAfterChangingModtimeOnly run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zegicih0cola'", Local "Local file system at /tmp/rclone3758268997", Modify Window "1ms" 2025/02/13 21:34:08 DEBUG : empty space: md5 = 1daeb00d4b1e7d6707ddff23d7fd227b OK 2025/02/13 21:34:08 DEBUG : empty space: Modification times differ by -95456h54m52.624456789s: 2011-12-25 12:59:59.123456789 +0000 UTC, 2001-02-03 04:05:06.499 +0000 UTC 2025/02/13 21:34:08 NOTICE: empty space: Skipped copy as --dry-run is set (size 1) 2025/02/13 21:34:08 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zegicih0cola': Waiting for checks to finish 2025/02/13 21:34:08 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zegicih0cola': Waiting for transfers to finish 2025/02/13 21:34:08 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zegicih0cola'", Local "Local file system at /tmp/rclone3758268997", Modify Window "1ms" 2025/02/13 21:34:09 DEBUG : empty space: Modification times differ by -95456h54m52.624456789s: 2011-12-25 12:59:59.123456789 +0000 UTC, 2001-02-03 04:05:06.499 +0000 UTC 2025/02/13 21:34:09 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zegicih0cola': Waiting for checks to finish 2025/02/13 21:34:09 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zegicih0cola': Waiting for transfers to finish 2025/02/13 21:34:10 DEBUG : empty space: md5 = 9f92629c0f335126bf778e2f6424812d OK 2025/02/13 21:34:10 INFO : empty space: Copied (replaced existing) 2025/02/13 21:34:10 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zegicih0cola'", Local "Local file system at /tmp/rclone3758268997", Modify Window "1ms" --- PASS: TestSyncAfterChangingModtimeOnly (5.54s) === RUN TestSyncAfterChangingModtimeOnlyWithNoUpdateModTime run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zegicih0cola'", Local "Local file system at /tmp/rclone3758268997", Modify Window "1ms" sync_test.go:1016: Can't check this if no hashes supported --- PASS: TestSyncAfterChangingModtimeOnlyWithNoUpdateModTime (0.48s) === RUN TestSyncDoesntUpdateModtime run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zegicih0cola'", Local "Local file system at /tmp/rclone3758268997", Modify Window "1ms" 2025/02/13 21:34:14 DEBUG : foo: md5 = 81f33b99f077a1303ab743d0180398e4 OK 2025/02/13 21:34:14 DEBUG : foo: Modification times differ by -95456h54m52.624456789s: 2011-12-25 12:59:59.123456789 +0000 UTC, 2001-02-03 04:05:06.499 +0000 UTC 2025/02/13 21:34:14 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zegicih0cola': Waiting for checks to finish 2025/02/13 21:34:14 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zegicih0cola': Waiting for transfers to finish 2025/02/13 21:34:16 DEBUG : foo: md5 = d729823b33f7e9db302750e1dd4a5828 OK 2025/02/13 21:34:16 INFO : foo: Copied (replaced existing) 2025/02/13 21:34:16 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zegicih0cola'", Local "Local file system at /tmp/rclone3758268997", Modify Window "1ms" --- PASS: TestSyncDoesntUpdateModtime (4.96s) === RUN TestSyncAfterAddingAFile run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zegicih0cola'", Local "Local file system at /tmp/rclone3758268997", Modify Window "1ms" 2025/02/13 21:34:19 DEBUG : empty space: md5 = 8ebd446d21f6e1edabc0c707d04d9570 OK 2025/02/13 21:34:19 DEBUG : potato: Need to transfer - File not found at Destination 2025/02/13 21:34:19 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zegicih0cola': Waiting for checks to finish 2025/02/13 21:34:19 DEBUG : empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/02/13 21:34:19 DEBUG : empty space: Unchanged skipping 2025/02/13 21:34:19 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zegicih0cola': Waiting for transfers to finish 2025/02/13 21:34:20 DEBUG : potato: md5 = 820d9cc833d99b5291c99c3109d29d69 OK 2025/02/13 21:34:20 INFO : potato: Copied (new) 2025/02/13 21:34:20 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zegicih0cola'", Local "Local file system at /tmp/rclone3758268997", Modify Window "1ms" --- PASS: TestSyncAfterAddingAFile (5.07s) === RUN TestSyncAfterChangingFilesSizeOnly run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zegicih0cola'", Local "Local file system at /tmp/rclone3758268997", Modify Window "1ms" 2025/02/13 21:34:24 DEBUG : potato: md5 = 2290a95d1d47e90873fa1c6021dded6d OK 2025/02/13 21:34:24 DEBUG : potato: Sizes differ (src 21 vs dst 60) 2025/02/13 21:34:24 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zegicih0cola': Waiting for checks to finish 2025/02/13 21:34:24 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zegicih0cola': Waiting for transfers to finish 2025/02/13 21:34:26 DEBUG : potato: md5 = e396125fbb66169cd0d9056638eab364 OK 2025/02/13 21:34:26 INFO : potato: Copied (replaced existing) 2025/02/13 21:34:26 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zegicih0cola'", Local "Local file system at /tmp/rclone3758268997", Modify Window "1ms" --- PASS: TestSyncAfterChangingFilesSizeOnly (4.70s) === RUN TestSyncAfterChangingContentsOnly run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zegicih0cola'", Local "Local file system at /tmp/rclone3758268997", Modify Window "1ms" 2025/02/13 21:34:28 DEBUG : potato: md5 = 49243022985151bef03153d1aacb8272 OK 2025/02/13 21:34:29 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zegicih0cola': Waiting for checks to finish 2025/02/13 21:34:29 DEBUG : potato: Modification times differ by 119h59m59.876543211s: 2011-12-25 12:59:59.123456789 +0000 UTC, 2011-12-30 12:59:59 +0000 UTC 2025/02/13 21:34:29 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zegicih0cola': Waiting for transfers to finish 2025/02/13 21:34:30 DEBUG : potato: md5 = 7d91f233da9104bb1cd6784cd91fd06b OK 2025/02/13 21:34:30 INFO : potato: Copied (replaced existing) 2025/02/13 21:34:30 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zegicih0cola'", Local "Local file system at /tmp/rclone3758268997", Modify Window "1ms" --- PASS: TestSyncAfterChangingContentsOnly (4.66s) === RUN TestSyncAfterRemovingAFileAndAddingAFileDryRun run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zegicih0cola'", Local "Local file system at /tmp/rclone3758268997", Modify Window "1ms" 2025/02/13 21:34:33 DEBUG : potato: md5 = 01494d07c9f5e7e8d8f9193c6befd758 OK 2025/02/13 21:34:34 DEBUG : empty space: md5 = 8477c15d4e6357a2e55af09ca8f9cc3b OK 2025/02/13 21:34:35 DEBUG : potato2: Need to transfer - File not found at Destination 2025/02/13 21:34:35 NOTICE: potato2: Skipped copy as --dry-run is set (size 60) 2025/02/13 21:34:35 DEBUG : empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/02/13 21:34:35 DEBUG : empty space: Unchanged skipping 2025/02/13 21:34:35 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zegicih0cola': Waiting for checks to finish 2025/02/13 21:34:35 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zegicih0cola': Waiting for transfers to finish 2025/02/13 21:34:35 DEBUG : Waiting for deletions to finish 2025/02/13 21:34:35 NOTICE: potato: Skipped delete as --dry-run is set (size 21) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zegicih0cola'", Local "Local file system at /tmp/rclone3758268997", Modify Window "1ms" --- PASS: TestSyncAfterRemovingAFileAndAddingAFileDryRun (5.22s) === RUN TestSyncAfterRemovingAFileAndAddingAFile run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zegicih0cola'", Local "Local file system at /tmp/rclone3758268997", Modify Window "1ms" 2025/02/13 21:34:38 DEBUG : potato: md5 = 3778b7a0fd32496bfaeb7aabd9ca418c OK 2025/02/13 21:34:40 DEBUG : empty space: md5 = 80a6eea94fc33766d9d4e207655cd221 OK 2025/02/13 21:34:40 DEBUG : potato2: Need to transfer - File not found at Destination 2025/02/13 21:34:40 DEBUG : empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/02/13 21:34:40 DEBUG : empty space: Unchanged skipping 2025/02/13 21:34:40 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zegicih0cola': Waiting for checks to finish 2025/02/13 21:34:40 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zegicih0cola': Waiting for transfers to finish 2025/02/13 21:34:42 DEBUG : potato2: md5 = aeb68f691e376fac261d35fb8f4f4172 OK 2025/02/13 21:34:42 INFO : potato2: Copied (new) 2025/02/13 21:34:42 DEBUG : Waiting for deletions to finish 2025/02/13 21:34:42 INFO : potato: Deleted run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zegicih0cola'", Local "Local file system at /tmp/rclone3758268997", Modify Window "1ms" --- PASS: TestSyncAfterRemovingAFileAndAddingAFile (7.36s) === RUN TestSyncAfterRemovingAFileAndAddingAFileSubDir run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zegicih0cola'", Local "Local file system at /tmp/rclone3758268997", Modify Window "1ms" 2025/02/13 21:34:47 DEBUG : b/potato: md5 = ed1a96634fbd38bc85ffef31140648f0 OK 2025/02/13 21:34:49 DEBUG : c/non empty space: md5 = f8634b60d991ed77a50638325cfe4749 OK 2025/02/13 21:34:49 INFO : d: Making directory 2025/02/13 21:34:49 INFO : d/e: Making directory 2025/02/13 21:34:51 DEBUG : Added delayed dir = "a", newDst= 2025/02/13 21:34:51 DEBUG : Added delayed dir = "c", newDst=c 2025/02/13 21:34:51 DEBUG : a/potato2: Need to transfer - File not found at Destination 2025/02/13 21:34:51 DEBUG : c/non empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/02/13 21:34:51 DEBUG : c/non empty space: Unchanged skipping 2025/02/13 21:34:52 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zegicih0cola': Waiting for checks to finish 2025/02/13 21:34:52 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zegicih0cola': Waiting for transfers to finish 2025/02/13 21:34:53 DEBUG : a/potato2: md5 = 8fe81961a46967659a1ca8e8736543df OK 2025/02/13 21:34:53 INFO : a/potato2: Copied (new) 2025/02/13 21:34:53 DEBUG : Waiting for deletions to finish 2025/02/13 21:34:54 INFO : b/potato: Deleted 2025/02/13 21:34:54 INFO : a: Set directory modification time (using DirSetModTime) 2025/02/13 21:34:54 INFO : d/e: Removing directory 2025/02/13 21:34:55 INFO : d: Removing directory 2025/02/13 21:34:55 DEBUG : ka6id8d20d3s5ktapedlphgta8: Rmdir: contains trashed file: "r8sppajuabeak3sbgj2ak8vuf8" 2025/02/13 21:34:56 INFO : b: Removing directory 2025/02/13 21:34:56 DEBUG : 32d8ua6196mc1r7qkfog53rkg0: Rmdir: contains trashed file: "2m507n64kafsi59v9q71r281a4" 2025/02/13 21:34:56 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zegicih0cola': deleted 3 directories run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zegicih0cola'", Local "Local file system at /tmp/rclone3758268997", Modify Window "1ms" 2025/02/13 21:34:59 DEBUG : 3i9du405pfogq3ncai6pg7ouio: Rmdir: contains trashed file: "982d3pss7t5pn0il16r2foj31s" 2025/02/13 21:34:59 DEBUG : 2bsvlrk2ne1lfitm6tttcu0qt8: Rmdir: contains trashed file: "89l8renevh3mji1c8r1p7qn6tg" --- PASS: TestSyncAfterRemovingAFileAndAddingAFileSubDir (16.13s) === RUN TestSyncAfterRemovingAFileAndAddingAFileSubDirWithErrors run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zegicih0cola'", Local "Local file system at /tmp/rclone3758268997", Modify Window "1ms" 2025/02/13 21:35:03 DEBUG : b/potato: md5 = b7b9e071be2084bcf33309c9f8eb3cff OK 2025/02/13 21:35:05 DEBUG : c/non empty space: md5 = 2cf0c80bd3ec172638b69fd4995bf2b4 OK 2025/02/13 21:35:05 INFO : d: Making directory 2025/02/13 21:35:06 DEBUG : Added delayed dir = "a", newDst= 2025/02/13 21:35:06 DEBUG : Added delayed dir = "c", newDst=c 2025/02/13 21:35:06 DEBUG : a/potato2: Need to transfer - File not found at Destination 2025/02/13 21:35:07 DEBUG : c/non empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/02/13 21:35:07 DEBUG : c/non empty space: Unchanged skipping 2025/02/13 21:35:07 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zegicih0cola': Waiting for checks to finish 2025/02/13 21:35:07 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zegicih0cola': Waiting for transfers to finish 2025/02/13 21:35:09 DEBUG : a/potato2: md5 = c09601b71b2cb695f329bf397c9b6fe6 OK 2025/02/13 21:35:09 INFO : a/potato2: Copied (new) 2025/02/13 21:35:09 ERROR : Encrypted drive 'TestCryptDrive:rclone-test-zegicih0cola': not deleting files as there were IO errors 2025/02/13 21:35:09 INFO : a: Set directory modification time (using DirSetModTime) 2025/02/13 21:35:09 ERROR : Encrypted drive 'TestCryptDrive:rclone-test-zegicih0cola': not deleting directories as there were IO errors run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zegicih0cola'", Local "Local file system at /tmp/rclone3758268997", Modify Window "1ms" 2025/02/13 21:35:12 DEBUG : 3i9du405pfogq3ncai6pg7ouio: Rmdir: contains trashed file: "982d3pss7t5pn0il16r2foj31s" 2025/02/13 21:35:13 DEBUG : 32d8ua6196mc1r7qkfog53rkg0: Rmdir: contains trashed file: "2m507n64kafsi59v9q71r281a4" 2025/02/13 21:35:14 DEBUG : 2bsvlrk2ne1lfitm6tttcu0qt8: Rmdir: contains trashed file: "89l8renevh3mji1c8r1p7qn6tg" --- PASS: TestSyncAfterRemovingAFileAndAddingAFileSubDirWithErrors (14.28s) === RUN TestSyncDeleteAfter --- PASS: TestSyncDeleteAfter (0.00s) === RUN TestSyncDeleteDuring run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zegicih0cola'", Local "Local file system at /tmp/rclone3758268997", Modify Window "1ms" 2025/02/13 21:35:16 DEBUG : potato: md5 = 79e3a2d8b9b38f09700b4158f4fb9682 OK 2025/02/13 21:35:17 DEBUG : empty space: md5 = 1b081e08da33a0244247020cc49ea998 OK 2025/02/13 21:35:18 DEBUG : Waiting for deletions to finish 2025/02/13 21:35:18 DEBUG : potato2: Need to transfer - File not found at Destination 2025/02/13 21:35:18 DEBUG : empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/02/13 21:35:18 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zegicih0cola': Waiting for checks to finish 2025/02/13 21:35:18 DEBUG : empty space: Unchanged skipping 2025/02/13 21:35:18 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zegicih0cola': Waiting for transfers to finish 2025/02/13 21:35:18 INFO : potato: Deleted 2025/02/13 21:35:19 DEBUG : potato2: md5 = eeded0d22896c81c235aeba638dd93c9 OK 2025/02/13 21:35:19 INFO : potato2: Copied (new) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zegicih0cola'", Local "Local file system at /tmp/rclone3758268997", Modify Window "1ms" --- PASS: TestSyncDeleteDuring (7.21s) === RUN TestSyncDeleteBefore run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zegicih0cola'", Local "Local file system at /tmp/rclone3758268997", Modify Window "1ms" 2025/02/13 21:35:23 DEBUG : potato: md5 = 026e3a790ab16d5c9ec31abc1cb2ce2a OK 2025/02/13 21:35:25 DEBUG : empty space: md5 = af76a92e83f06c6618ac42a023476727 OK 2025/02/13 21:35:25 DEBUG : Waiting for deletions to finish 2025/02/13 21:35:25 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zegicih0cola': Waiting for checks to finish 2025/02/13 21:35:25 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zegicih0cola': Waiting for transfers to finish 2025/02/13 21:35:26 INFO : potato: Deleted 2025/02/13 21:35:26 DEBUG : potato2: Need to transfer - File not found at Destination 2025/02/13 21:35:26 DEBUG : empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/02/13 21:35:26 DEBUG : empty space: Unchanged skipping 2025/02/13 21:35:26 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zegicih0cola': Waiting for checks to finish 2025/02/13 21:35:26 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zegicih0cola': Waiting for transfers to finish 2025/02/13 21:35:27 DEBUG : potato2: md5 = 51f07a6b631529415d36af3eabcbbb2a OK 2025/02/13 21:35:27 INFO : potato2: Copied (new) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zegicih0cola'", Local "Local file system at /tmp/rclone3758268997", Modify Window "1ms" --- PASS: TestSyncDeleteBefore (7.70s) === RUN TestCopyDeleteBefore run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zegicih0cola'", Local "Local file system at /tmp/rclone3758268997", Modify Window "1ms" 2025/02/13 21:35:31 DEBUG : potato: md5 = ebd5ce4f9bf31fd4214281f2496b56ae OK 2025/02/13 21:35:31 DEBUG : potato2: Need to transfer - File not found at Destination 2025/02/13 21:35:31 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zegicih0cola': Waiting for checks to finish 2025/02/13 21:35:31 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zegicih0cola': Waiting for transfers to finish 2025/02/13 21:35:33 DEBUG : potato2: md5 = c90b5362914c781c0684effb802bf3e7 OK 2025/02/13 21:35:33 INFO : potato2: Copied (new) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zegicih0cola'", Local "Local file system at /tmp/rclone3758268997", Modify Window "1ms" --- PASS: TestCopyDeleteBefore (5.21s) === RUN TestSyncWithExclude run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zegicih0cola'", Local "Local file system at /tmp/rclone3758268997", Modify Window "1ms" 2025/02/13 21:35:36 DEBUG : potato2: md5 = f005f43a018020108cd2d86ea0ab30ce OK 2025/02/13 21:35:37 DEBUG : empty space: md5 = 7bb787012c6f4451de5eb7f4ac00c70c OK 2025/02/13 21:35:38 DEBUG : enormous: Excluded (Size Filter) 2025/02/13 21:35:38 DEBUG : enormous: Excluded 2025/02/13 21:35:38 DEBUG : potato2: Excluded (Size Filter) 2025/02/13 21:35:38 DEBUG : potato2: Excluded 2025/02/13 21:35:38 DEBUG : potato2: Excluded (Size Filter) 2025/02/13 21:35:38 DEBUG : potato2: Excluded 2025/02/13 21:35:38 DEBUG : empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/02/13 21:35:38 DEBUG : empty space: Unchanged skipping 2025/02/13 21:35:38 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zegicih0cola': Waiting for checks to finish 2025/02/13 21:35:38 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zegicih0cola': Waiting for transfers to finish 2025/02/13 21:35:38 DEBUG : Waiting for deletions to finish 2025/02/13 21:35:38 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zegicih0cola'", Local "Local file system at /tmp/rclone3758268997", Modify Window "1ms" 2025/02/13 21:35:38 DEBUG : enormous: Excluded (Size Filter) 2025/02/13 21:35:38 DEBUG : enormous: Excluded 2025/02/13 21:35:38 DEBUG : potato2: Excluded (Size Filter) 2025/02/13 21:35:38 DEBUG : potato2: Excluded 2025/02/13 21:35:38 DEBUG : potato2: Excluded (Size Filter) 2025/02/13 21:35:38 DEBUG : potato2: Excluded 2025/02/13 21:35:38 DEBUG : empty space: Size and modification time the same (differ by 456.789µs, within tolerance 1ms) 2025/02/13 21:35:38 DEBUG : empty space: Unchanged skipping 2025/02/13 21:35:38 DEBUG : Local file system at /tmp/rclone3758268997: Waiting for checks to finish 2025/02/13 21:35:38 DEBUG : Local file system at /tmp/rclone3758268997: Waiting for transfers to finish 2025/02/13 21:35:38 DEBUG : Waiting for deletions to finish 2025/02/13 21:35:38 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zegicih0cola'", Local "Local file system at /tmp/rclone3758268997", Modify Window "1ms" --- PASS: TestSyncWithExclude (7.92s) === RUN TestSyncWithExcludeAndDeleteExcluded run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zegicih0cola'", Local "Local file system at /tmp/rclone3758268997", Modify Window "1ms" 2025/02/13 21:35:44 DEBUG : potato2: md5 = 419ec9c9052a4e518a26dff5a18cfc63 OK 2025/02/13 21:35:46 DEBUG : empty space: md5 = 78448421a8cd0dfb0bdd646d3aa2d809 OK 2025/02/13 21:35:47 DEBUG : enormous: md5 = 7e2d87eedb713400c43d345cb48ac02c OK 2025/02/13 21:35:47 DEBUG : enormous: Excluded (Size Filter) 2025/02/13 21:35:47 DEBUG : enormous: Excluded 2025/02/13 21:35:47 DEBUG : potato2: Excluded (Size Filter) 2025/02/13 21:35:47 DEBUG : potato2: Excluded 2025/02/13 21:35:48 DEBUG : empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/02/13 21:35:48 DEBUG : empty space: Unchanged skipping 2025/02/13 21:35:48 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zegicih0cola': Waiting for checks to finish 2025/02/13 21:35:48 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zegicih0cola': Waiting for transfers to finish 2025/02/13 21:35:48 DEBUG : Waiting for deletions to finish 2025/02/13 21:35:48 INFO : enormous: Deleted 2025/02/13 21:35:48 INFO : potato2: Deleted 2025/02/13 21:35:48 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zegicih0cola'", Local "Local file system at /tmp/rclone3758268997", Modify Window "1ms" 2025/02/13 21:35:48 DEBUG : empty space: Size and modification time the same (differ by 456.789µs, within tolerance 1ms) 2025/02/13 21:35:48 DEBUG : empty space: Unchanged skipping 2025/02/13 21:35:48 DEBUG : Local file system at /tmp/rclone3758268997: Waiting for checks to finish 2025/02/13 21:35:48 DEBUG : Local file system at /tmp/rclone3758268997: Waiting for transfers to finish 2025/02/13 21:35:48 DEBUG : Waiting for deletions to finish 2025/02/13 21:35:48 INFO : enormous: Deleted 2025/02/13 21:35:48 INFO : potato2: Deleted 2025/02/13 21:35:48 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zegicih0cola'", Local "Local file system at /tmp/rclone3758268997", Modify Window "1ms" --- PASS: TestSyncWithExcludeAndDeleteExcluded (7.55s) === RUN TestSyncWithUpdateOlder run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zegicih0cola'", Local "Local file system at /tmp/rclone3758268997", Modify Window "1ms" 2025/02/13 21:35:52 DEBUG : one: md5 = 6a1a2af6fd474024256caf8c01e2f1d8 OK 2025/02/13 21:35:53 DEBUG : two: md5 = 7f5c42344b7db74eb92bec3ceb2095f6 OK 2025/02/13 21:35:53 DEBUG : Config file has changed externally - reloading 2025/02/13 21:35:53 DEBUG : TestDrive: Loaded fresh token from config file 2025/02/13 21:35:54 DEBUG : three: md5 = ff5e1ef5d878a80a41893bb415704e8a OK 2025/02/13 21:35:56 DEBUG : four: md5 = 454d8526318e2360b24f1037be6b097b OK 2025/02/13 21:35:56 DEBUG : five: Need to transfer - File not found at Destination 2025/02/13 21:35:56 DEBUG : four: Sizes differ (src 4 vs dst 8) 2025/02/13 21:35:56 DEBUG : three: Sizes identical 2025/02/13 21:35:56 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zegicih0cola': Waiting for checks to finish 2025/02/13 21:35:56 DEBUG : one: Destination is newer than source, skipping 2025/02/13 21:35:56 DEBUG : four: Destination mod time is within 1s of source but files differ, transferring 2025/02/13 21:35:56 DEBUG : three: Destination mod time is within 1s of source and files identical, skipping 2025/02/13 21:35:56 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zegicih0cola': Waiting for transfers to finish 2025/02/13 21:35:57 DEBUG : four: md5 = 37edb22430daf0493dee384e60170fe9 OK 2025/02/13 21:35:57 INFO : four: Copied (replaced existing) 2025/02/13 21:35:57 DEBUG : two: md5 = ede091d11c37fa80933c88f3f751e0ee OK 2025/02/13 21:35:57 INFO : two: Copied (replaced existing) 2025/02/13 21:35:57 DEBUG : five: md5 = b355174898d646294572cb92be4886c7 OK 2025/02/13 21:35:57 INFO : five: Copied (new) 2025/02/13 21:35:57 DEBUG : Waiting for deletions to finish sync_test.go:1449: Skip test with --checksum as no hashes supported --- PASS: TestSyncWithUpdateOlder (10.44s) === 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-zegicih0cola'", Local "Local file system at /tmp/rclone3758268997", Modify Window "1ms" sync_test.go:1538: Can track renames: false 2025/02/13 21:36:01 ERROR : Encrypted drive 'TestCryptDrive:rclone-test-zegicih0cola': Ignoring --track-renames as the source and destination do not have a common hash 2025/02/13 21:36:01 DEBUG : potato: Need to transfer - File not found at Destination 2025/02/13 21:36:01 DEBUG : yam: Need to transfer - File not found at Destination 2025/02/13 21:36:01 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zegicih0cola': Waiting for checks to finish 2025/02/13 21:36:01 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zegicih0cola': Waiting for transfers to finish 2025/02/13 21:36:02 DEBUG : potato: md5 = 2cb9b3806137196264caa2dab5fe03aa OK 2025/02/13 21:36:02 INFO : potato: Copied (new) 2025/02/13 21:36:03 DEBUG : yam: md5 = 01dacc36a1090c4f2974184e38d09da3 OK 2025/02/13 21:36:03 INFO : yam: Copied (new) 2025/02/13 21:36:03 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zegicih0cola'", Local "Local file system at /tmp/rclone3758268997", Modify Window "1ms" 2025/02/13 21:36:03 ERROR : Encrypted drive 'TestCryptDrive:rclone-test-zegicih0cola': Ignoring --track-renames as the source and destination do not have a common hash 2025/02/13 21:36:03 DEBUG : yaml: Need to transfer - File not found at Destination 2025/02/13 21:36:03 DEBUG : potato: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/02/13 21:36:03 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zegicih0cola': Waiting for checks to finish 2025/02/13 21:36:03 DEBUG : potato: Unchanged skipping 2025/02/13 21:36:03 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zegicih0cola': Waiting for transfers to finish 2025/02/13 21:36:05 DEBUG : yaml: md5 = 590fa1d427e309122b297aeb93d36405 OK 2025/02/13 21:36:05 INFO : yaml: Copied (new) 2025/02/13 21:36:05 DEBUG : Waiting for deletions to finish 2025/02/13 21:36:05 INFO : yam: Deleted run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zegicih0cola'", Local "Local file system at /tmp/rclone3758268997", Modify Window "1ms" --- PASS: TestSyncWithTrackRenames (6.96s) === RUN TestParseRenamesStrategyModtime --- PASS: TestParseRenamesStrategyModtime (0.00s) === RUN TestRenamesStrategyModtime --- PASS: TestRenamesStrategyModtime (0.00s) === RUN TestSyncWithTrackRenamesStrategyModtime run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zegicih0cola'", Local "Local file system at /tmp/rclone3758268997", Modify Window "1ms" sync_test.go:1610: Can track renames: true 2025/02/13 21:36:08 INFO : Encrypted drive 'TestCryptDrive:rclone-test-zegicih0cola': Making map for --track-renames 2025/02/13 21:36:08 INFO : Encrypted drive 'TestCryptDrive:rclone-test-zegicih0cola': Finished making map for --track-renames 2025/02/13 21:36:08 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zegicih0cola': Waiting for checks to finish 2025/02/13 21:36:08 DEBUG : potato: Need to transfer - No matching file found at Destination 2025/02/13 21:36:08 DEBUG : yam: Need to transfer - No matching file found at Destination 2025/02/13 21:36:08 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zegicih0cola': Waiting for renames to finish 2025/02/13 21:36:08 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zegicih0cola': Waiting for transfers to finish 2025/02/13 21:36:09 DEBUG : potato: md5 = 830948d5582e7a0ac207c813f7706332 OK 2025/02/13 21:36:09 INFO : potato: Copied (new) 2025/02/13 21:36:09 DEBUG : yam: md5 = cfb9c3c111abc6132cedab7ff2cfff10 OK 2025/02/13 21:36:09 INFO : yam: Copied (new) 2025/02/13 21:36:09 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zegicih0cola'", Local "Local file system at /tmp/rclone3758268997", Modify Window "1ms" 2025/02/13 21:36:10 DEBUG : potato: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/02/13 21:36:10 INFO : Encrypted drive 'TestCryptDrive:rclone-test-zegicih0cola': Making map for --track-renames 2025/02/13 21:36:10 INFO : Encrypted drive 'TestCryptDrive:rclone-test-zegicih0cola': Finished making map for --track-renames 2025/02/13 21:36:10 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zegicih0cola': Waiting for checks to finish 2025/02/13 21:36:10 DEBUG : potato: Unchanged skipping 2025/02/13 21:36:10 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zegicih0cola': Waiting for renames to finish 2025/02/13 21:36:11 INFO : yam: Moved (server-side) to: yaml 2025/02/13 21:36:11 INFO : yaml: Renamed from "yam" 2025/02/13 21:36:11 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zegicih0cola': Waiting for transfers to finish 2025/02/13 21:36:11 DEBUG : Waiting for deletions to finish 2025/02/13 21:36:11 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zegicih0cola'", Local "Local file system at /tmp/rclone3758268997", Modify Window "1ms" --- PASS: TestSyncWithTrackRenamesStrategyModtime (5.67s) === RUN TestSyncWithTrackRenamesStrategyLeaf run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zegicih0cola'", Local "Local file system at /tmp/rclone3758268997", Modify Window "1ms" sync_test.go:1649: Can track renames: true 2025/02/13 21:36:14 DEBUG : Added delayed dir = "sub", newDst= 2025/02/13 21:36:14 INFO : Encrypted drive 'TestCryptDrive:rclone-test-zegicih0cola': Making map for --track-renames 2025/02/13 21:36:14 INFO : Encrypted drive 'TestCryptDrive:rclone-test-zegicih0cola': Finished making map for --track-renames 2025/02/13 21:36:14 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zegicih0cola': Waiting for checks to finish 2025/02/13 21:36:14 DEBUG : potato: Need to transfer - No matching file found at Destination 2025/02/13 21:36:14 DEBUG : sub/yam: Need to transfer - No matching file found at Destination 2025/02/13 21:36:14 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zegicih0cola': Waiting for renames to finish 2025/02/13 21:36:14 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zegicih0cola': Waiting for transfers to finish 2025/02/13 21:36:16 DEBUG : sub/yam: md5 = 851e8e623ea855479ab945a9911e3abf OK 2025/02/13 21:36:16 INFO : sub/yam: Copied (new) 2025/02/13 21:36:16 DEBUG : potato: md5 = e0255b008f46b7b119d20507801b8e5a OK 2025/02/13 21:36:16 INFO : potato: Copied (new) 2025/02/13 21:36:16 DEBUG : Waiting for deletions to finish 2025/02/13 21:36:16 INFO : sub: Set directory modification time (using DirSetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zegicih0cola'", Local "Local file system at /tmp/rclone3758268997", Modify Window "1ms" 2025/02/13 21:36:17 DEBUG : Added delayed dir = "sub", newDst=sub 2025/02/13 21:36:17 DEBUG : potato: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/02/13 21:36:17 DEBUG : potato: Unchanged skipping 2025/02/13 21:36:18 INFO : Encrypted drive 'TestCryptDrive:rclone-test-zegicih0cola': Making map for --track-renames 2025/02/13 21:36:18 INFO : Encrypted drive 'TestCryptDrive:rclone-test-zegicih0cola': Finished making map for --track-renames 2025/02/13 21:36:18 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zegicih0cola': Waiting for checks to finish 2025/02/13 21:36:18 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zegicih0cola': Waiting for renames to finish 2025/02/13 21:36:18 INFO : sub/yam: Moved (server-side) to: yam 2025/02/13 21:36:18 INFO : yam: Renamed from "sub/yam" 2025/02/13 21:36:18 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zegicih0cola': Waiting for transfers to finish 2025/02/13 21:36:18 DEBUG : Waiting for deletions to finish 2025/02/13 21:36:18 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zegicih0cola'", Local "Local file system at /tmp/rclone3758268997", Modify Window "1ms" --- PASS: TestSyncWithTrackRenamesStrategyLeaf (8.78s) === RUN TestServerSideMoveLocal run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zegicih0cola'", Local "Local file system at /tmp/rclone3758268997", Modify Window "1ms" 2025/02/13 21:36:22 DEBUG : Creating backend with remote "/tmp/rclone3758268997/dir1" 2025/02/13 21:36:22 DEBUG : Creating backend with remote "/tmp/rclone3758268997/dir2" 2025/02/13 21:36:22 DEBUG : Local file system at /tmp/rclone3758268997/dir2: Using server-side directory move 2025/02/13 21:36:22 INFO : Local file system at /tmp/rclone3758268997/dir2: Server side directory move failed - fallback to file moves: can't copy directory - destination already exists 2025/02/13 21:36:22 DEBUG : file1.txt: Need to transfer - File not found at Destination 2025/02/13 21:36:22 DEBUG : Local file system at /tmp/rclone3758268997/dir2: Waiting for checks to finish 2025/02/13 21:36:22 DEBUG : Local file system at /tmp/rclone3758268997/dir2: Waiting for transfers to finish 2025/02/13 21:36:22 INFO : file1.txt: Moved (server-side) --- PASS: TestServerSideMoveLocal (0.54s) === RUN TestMoveWithDeleteEmptySrcDirs run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zegicih0cola'", Local "Local file system at /tmp/rclone3758268997", Modify Window "1ms" 2025/02/13 21:36:23 DEBUG : Added delayed dir = "nested", newDst= 2025/02/13 21:36:23 DEBUG : Added delayed dir = "sub dir", newDst= 2025/02/13 21:36:23 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2025/02/13 21:36:23 DEBUG : Added delayed dir = "nested/sub dir", newDst= 2025/02/13 21:36:23 DEBUG : nested/sub dir/file: Need to transfer - File not found at Destination 2025/02/13 21:36:23 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zegicih0cola': Waiting for checks to finish 2025/02/13 21:36:23 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zegicih0cola': Waiting for transfers to finish 2025/02/13 21:36:25 DEBUG : sub dir/hello world: md5 = bbbebf184efc91e769d62ad551738aaf OK 2025/02/13 21:36:25 INFO : sub dir/hello world: Copied (new) 2025/02/13 21:36:25 INFO : sub dir/hello world: Deleted 2025/02/13 21:36:27 DEBUG : nested/sub dir/file: md5 = 0607b6a7852f5486c6b5517d1da6a5ac OK 2025/02/13 21:36:27 INFO : nested/sub dir/file: Copied (new) 2025/02/13 21:36:27 INFO : nested/sub dir/file: Deleted 2025/02/13 21:36:28 INFO : nested/sub dir: Set directory modification time (using DirSetModTime) 2025/02/13 21:36:28 INFO : sub dir: Set directory modification time (using DirSetModTime) 2025/02/13 21:36:28 INFO : nested: Set directory modification time (using DirSetModTime) 2025/02/13 21:36:28 INFO : sub dir: Removing directory 2025/02/13 21:36:28 INFO : nested/sub dir: Removing directory 2025/02/13 21:36:28 INFO : nested: Removing directory 2025/02/13 21:36:28 DEBUG : Local file system at /tmp/rclone3758268997: deleted 3 directories run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zegicih0cola'", Local "Local file system at /tmp/rclone3758268997", Modify Window "1ms" 2025/02/13 21:36:31 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" 2025/02/13 21:36:32 DEBUG : 37qp6d1gohacv723ij3brofbu8/14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "ftp4kuv8se7tqduu6pmmcvjsmk" 2025/02/13 21:36:32 DEBUG : 37qp6d1gohacv723ij3brofbu8: Rmdir: contains trashed file: "14begaa36ih249fgrnfk6nulg0" --- PASS: TestMoveWithDeleteEmptySrcDirs (10.80s) === RUN TestMoveWithoutDeleteEmptySrcDirs run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zegicih0cola'", Local "Local file system at /tmp/rclone3758268997", Modify Window "1ms" 2025/02/13 21:36:34 DEBUG : Added delayed dir = "nested", newDst= 2025/02/13 21:36:34 DEBUG : Added delayed dir = "sub dir", newDst= 2025/02/13 21:36:34 DEBUG : Added delayed dir = "nested/sub dir", newDst= 2025/02/13 21:36:34 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2025/02/13 21:36:34 DEBUG : nested/sub dir/file: Need to transfer - File not found at Destination 2025/02/13 21:36:34 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zegicih0cola': Waiting for checks to finish 2025/02/13 21:36:34 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zegicih0cola': Waiting for transfers to finish 2025/02/13 21:36:36 DEBUG : sub dir/hello world: md5 = 032b269d7d9b9da693ced16a1f3bc09a OK 2025/02/13 21:36:36 INFO : sub dir/hello world: Copied (new) 2025/02/13 21:36:36 INFO : sub dir/hello world: Deleted 2025/02/13 21:36:38 DEBUG : nested/sub dir/file: md5 = b2f5060b638a800226b352a11b64d03f OK 2025/02/13 21:36:38 INFO : nested/sub dir/file: Copied (new) 2025/02/13 21:36:38 INFO : nested/sub dir/file: Deleted 2025/02/13 21:36:38 INFO : nested/sub dir: Set directory modification time (using DirSetModTime) 2025/02/13 21:36:39 INFO : nested: Set directory modification time (using DirSetModTime) 2025/02/13 21:36:39 INFO : sub dir: Set directory modification time (using DirSetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zegicih0cola'", Local "Local file system at /tmp/rclone3758268997", Modify Window "1ms" 2025/02/13 21:36:41 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" 2025/02/13 21:36:42 DEBUG : 37qp6d1gohacv723ij3brofbu8/14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "ftp4kuv8se7tqduu6pmmcvjsmk" 2025/02/13 21:36:43 DEBUG : 37qp6d1gohacv723ij3brofbu8: Rmdir: contains trashed file: "14begaa36ih249fgrnfk6nulg0" --- PASS: TestMoveWithoutDeleteEmptySrcDirs (10.41s) === RUN TestMoveWithIgnoreExisting run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zegicih0cola'", Local "Local file system at /tmp/rclone3758268997", Modify Window "1ms" 2025/02/13 21:36:44 DEBUG : existing: Need to transfer - File not found at Destination 2025/02/13 21:36:44 DEBUG : existing-b: Need to transfer - File not found at Destination 2025/02/13 21:36:44 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zegicih0cola': Waiting for checks to finish 2025/02/13 21:36:44 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zegicih0cola': Waiting for transfers to finish 2025/02/13 21:36:45 DEBUG : existing: md5 = 2c01ab6a471b8919b3d1093c5fc15cf2 OK 2025/02/13 21:36:45 INFO : existing: Copied (new) 2025/02/13 21:36:45 INFO : existing: Deleted 2025/02/13 21:36:45 DEBUG : existing-b: md5 = 8cd63976d5f5d4e83d92d33e6e7eff6a OK 2025/02/13 21:36:45 INFO : existing-b: Copied (new) 2025/02/13 21:36:45 INFO : existing-b: Deleted 2025/02/13 21:36:46 DEBUG : existing: Destination exists, skipping 2025/02/13 21:36:46 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zegicih0cola': Waiting for checks to finish 2025/02/13 21:36:46 DEBUG : existing: Not removing source file as destination file exists and --ignore-existing is set 2025/02/13 21:36:46 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zegicih0cola': Waiting for transfers to finish 2025/02/13 21:36:46 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zegicih0cola'", Local "Local file system at /tmp/rclone3758268997", Modify Window "1ms" --- PASS: TestMoveWithIgnoreExisting (4.43s) === RUN TestServerSideMove run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zegicih0cola'", Local "Local file system at /tmp/rclone3758268997", Modify Window "1ms" 2025/02/13 21:36:48 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-sifejin5yure" 2025/02/13 21:36:48 DEBUG : Creating backend with remote "TestDrive:crypt/u4bluu2nac1s97tpat059pft3m0cfs6uvkuo1kttooquq8qs5t50" 2025/02/13 21:36:51 DEBUG : potato2: md5 = e554f926b76a38b73eb4992c1a5852bf OK 2025/02/13 21:36:52 DEBUG : empty space: md5 = c96cbe1f52531876e8938f40ae34283f OK 2025/02/13 21:36:54 DEBUG : potato3: md5 = 2d8beaf59bf3e09014841321c215971a OK sync_test.go:1705: Server side move (if possible) Encrypted drive 'TestCryptDrive:rclone-test-zegicih0cola' -> Encrypted drive 'TestCryptDrive:rclone-test-sifejin5yure' 2025/02/13 21:36:56 DEBUG : empty space: md5 = 148342fabbe333a8c07a537bb5858c2c OK 2025/02/13 21:36:58 DEBUG : potato3: md5 = 92a97db1412ccda6318773291f9550c6 OK 2025/02/13 21:36:58 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-sifejin5yure': Using server-side directory move 2025/02/13 21:36:58 INFO : Encrypted drive 'TestCryptDrive:rclone-test-sifejin5yure': Server side directory move failed - fallback to file moves: can't copy directory - destination already exists 2025/02/13 21:36:58 DEBUG : potato2: Need to transfer - File not found at Destination 2025/02/13 21:36:58 DEBUG : empty space: Size and modification time the same (differ by 0s, within tolerance 1ms) 2025/02/13 21:36:58 DEBUG : empty space: Unchanged skipping 2025/02/13 21:36:58 DEBUG : potato3: Sizes differ (src 68 vs dst 60) 2025/02/13 21:36:58 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-sifejin5yure': Waiting for checks to finish 2025/02/13 21:36:59 INFO : potato3: Deleted 2025/02/13 21:36:59 INFO : empty space: Deleted 2025/02/13 21:36:59 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-sifejin5yure': Waiting for transfers to finish 2025/02/13 21:36:59 INFO : potato2: Moved (server-side) 2025/02/13 21:36:59 INFO : potato3: Moved (server-side) 2025/02/13 21:37:00 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-ruketav8howa" 2025/02/13 21:37:00 DEBUG : Creating backend with remote "TestDrive:crypt/3e9vc21m2gneiajeskn40ipthcrv81vmmhhcnb4om2qnd0ka8l50" 2025/02/13 21:37:01 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-ruketav8howa': Using server-side directory move 2025/02/13 21:37:01 INFO : Encrypted drive 'TestCryptDrive:rclone-test-ruketav8howa': Server side directory move succeeded 2025/02/13 21:37:02 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-ruketav8howa': Purge remote 2025/02/13 21:37:03 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-sifejin5yure': Purge remote 2025/02/13 21:37:03 NOTICE: purge failed: directory not found --- PASS: TestServerSideMove (14.93s) === RUN TestServerSideMoveWithFilter run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zegicih0cola'", Local "Local file system at /tmp/rclone3758268997", Modify Window "1ms" 2025/02/13 21:37:03 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-vuqijas9gixa" 2025/02/13 21:37:03 DEBUG : Creating backend with remote "TestDrive:crypt/9q9vnsqfdccslis0g0g0bn3075miphlh3d4k86hgo8lrr69neceg" 2025/02/13 21:37:06 DEBUG : potato2: md5 = b6250387c568ea0b337a8cf45d5e124c OK 2025/02/13 21:37:07 DEBUG : empty space: md5 = 16a687041cee49e919d499b64c3bfdfe OK 2025/02/13 21:37:08 DEBUG : potato3: md5 = c8bf563edbb5cdefe813220c5eb24587 OK sync_test.go:1705: Server side move (if possible) Encrypted drive 'TestCryptDrive:rclone-test-zegicih0cola' -> Encrypted drive 'TestCryptDrive:rclone-test-vuqijas9gixa' 2025/02/13 21:37:10 DEBUG : empty space: md5 = 8724436d4062b48ea450cfaf86f18cfe OK 2025/02/13 21:37:12 DEBUG : potato3: md5 = 67120ac8be34eb0fd2262eadefc30f0a OK 2025/02/13 21:37:12 DEBUG : empty space: Excluded (Size Filter) 2025/02/13 21:37:12 DEBUG : empty space: Excluded 2025/02/13 21:37:12 DEBUG : empty space: Excluded (Size Filter) 2025/02/13 21:37:12 DEBUG : empty space: Excluded 2025/02/13 21:37:12 DEBUG : potato2: Need to transfer - File not found at Destination 2025/02/13 21:37:12 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vuqijas9gixa': Waiting for checks to finish 2025/02/13 21:37:12 DEBUG : potato3: Sizes differ (src 68 vs dst 60) 2025/02/13 21:37:12 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vuqijas9gixa': Waiting for transfers to finish 2025/02/13 21:37:13 INFO : potato2: Moved (server-side) 2025/02/13 21:37:13 INFO : potato3: Deleted 2025/02/13 21:37:14 INFO : potato3: Moved (server-side) 2025/02/13 21:37:14 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-koruvud6bova" 2025/02/13 21:37:14 DEBUG : Creating backend with remote "TestDrive:crypt/2s1g5q0e00flb1bd7r2hihj3ilcb7omruh3c3sgm5oemhniesio0" 2025/02/13 21:37:15 DEBUG : empty space: Excluded (Size Filter) 2025/02/13 21:37:15 DEBUG : empty space: Excluded 2025/02/13 21:37:15 DEBUG : potato2: Need to transfer - File not found at Destination 2025/02/13 21:37:15 DEBUG : potato3: Need to transfer - File not found at Destination 2025/02/13 21:37:15 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-koruvud6bova': Waiting for checks to finish 2025/02/13 21:37:15 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-koruvud6bova': Waiting for transfers to finish 2025/02/13 21:37:17 INFO : potato3: Moved (server-side) 2025/02/13 21:37:18 INFO : potato2: Moved (server-side) 2025/02/13 21:37:18 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-koruvud6bova': Purge remote 2025/02/13 21:37:19 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vuqijas9gixa': Purge remote --- PASS: TestServerSideMoveWithFilter (16.71s) === RUN TestServerSideMoveDeleteEmptySourceDirs run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zegicih0cola'", Local "Local file system at /tmp/rclone3758268997", Modify Window "1ms" 2025/02/13 21:37:20 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-furevuy8yoqo" 2025/02/13 21:37:20 DEBUG : Creating backend with remote "TestDrive:crypt/om4ppqeioo039i8r6ngvgc4q5r9uv77v0q0t6aqd08ae6kgjrf9g" 2025/02/13 21:37:22 DEBUG : potato2: md5 = fc798e41b24eb76119a7e3744b8785b3 OK 2025/02/13 21:37:24 DEBUG : empty space: md5 = 78d87df65320929abb9f88ab086348f5 OK 2025/02/13 21:37:25 DEBUG : potato3: md5 = 3ee71535dbfa422cdf2c58b3c35d2d2f OK 2025/02/13 21:37:25 INFO : tomatoDir: Making directory sync_test.go:1705: Server side move (if possible) Encrypted drive 'TestCryptDrive:rclone-test-zegicih0cola' -> Encrypted drive 'TestCryptDrive:rclone-test-furevuy8yoqo' 2025/02/13 21:37:29 DEBUG : empty space: md5 = 7705c0dcdf0b30828aedccc786af13b0 OK 2025/02/13 21:37:30 DEBUG : potato3: md5 = 75a75e6e1a44022fb1cb23a578b261a9 OK 2025/02/13 21:37:30 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-furevuy8yoqo': Using server-side directory move 2025/02/13 21:37:30 INFO : Encrypted drive 'TestCryptDrive:rclone-test-furevuy8yoqo': Server side directory move failed - fallback to file moves: can't copy directory - destination already exists 2025/02/13 21:37:31 DEBUG : potato2: Need to transfer - File not found at Destination 2025/02/13 21:37:31 DEBUG : Added delayed dir = "tomatoDir", newDst= 2025/02/13 21:37:31 DEBUG : empty space: Size and modification time the same (differ by 0s, within tolerance 1ms) 2025/02/13 21:37:31 DEBUG : empty space: Unchanged skipping 2025/02/13 21:37:31 DEBUG : potato3: Sizes differ (src 68 vs dst 60) 2025/02/13 21:37:31 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-furevuy8yoqo': Waiting for checks to finish 2025/02/13 21:37:31 INFO : potato3: Deleted 2025/02/13 21:37:31 INFO : empty space: Deleted 2025/02/13 21:37:31 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-furevuy8yoqo': Waiting for transfers to finish 2025/02/13 21:37:31 INFO : potato2: Moved (server-side) 2025/02/13 21:37:32 INFO : potato3: Moved (server-side) 2025/02/13 21:37:32 INFO : tomatoDir: Removing directory 2025/02/13 21:37:32 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zegicih0cola': deleted 1 directories 2025/02/13 21:37:33 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-yubobez2miwe" 2025/02/13 21:37:33 DEBUG : Creating backend with remote "TestDrive:crypt/svl7v2p293c7tds83abib61kor1getbb7njpet047ds644eq00m0" 2025/02/13 21:37:34 INFO : tomatoDir: Making directory 2025/02/13 21:37:35 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yubobez2miwe': Using server-side directory move 2025/02/13 21:37:35 INFO : Encrypted drive 'TestCryptDrive:rclone-test-yubobez2miwe': Server side directory move succeeded 2025/02/13 21:37:37 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yubobez2miwe': Purge remote 2025/02/13 21:37:38 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-furevuy8yoqo': Purge remote 2025/02/13 21:37:38 NOTICE: purge failed: directory not found --- PASS: TestServerSideMoveDeleteEmptySourceDirs (18.23s) === RUN TestServerSideMoveOverlap run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zegicih0cola'", Local "Local file system at /tmp/rclone3758268997", Modify Window "1ms" sync_test.go:1910: Skipping test as remote supports DirMove --- SKIP: TestServerSideMoveOverlap (0.45s) === RUN TestSyncOverlap run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zegicih0cola'", Local "Local file system at /tmp/rclone3758268997", Modify Window "1ms" 2025/02/13 21:37:39 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-zegicih0cola/rclone-sync-test" 2025/02/13 21:37:39 DEBUG : Creating backend with remote "TestDrive:crypt/acm2bl29gbtuhl9b1qh375055t9lo9mvu40inkr1thg9c16mrlrg/i7355aa0sb89uagn75vfjqr6s3e3e1h2et8in57abn1fe8qfego0" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zegicih0cola'", Local "Local file system at /tmp/rclone3758268997", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zegicih0cola'", Local "Local file system at /tmp/rclone3758268997", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zegicih0cola'", Local "Local file system at /tmp/rclone3758268997", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zegicih0cola'", Local "Local file system at /tmp/rclone3758268997", Modify Window "1ms" --- PASS: TestSyncOverlap (3.83s) === RUN TestSyncOverlapWithFilter run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zegicih0cola'", Local "Local file system at /tmp/rclone3758268997", Modify Window "1ms" 2025/02/13 21:37:43 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-zegicih0cola/rclone-sync-test" 2025/02/13 21:37:43 DEBUG : Creating backend with remote "TestDrive:crypt/acm2bl29gbtuhl9b1qh375055t9lo9mvu40inkr1thg9c16mrlrg/i7355aa0sb89uagn75vfjqr6s3e3e1h2et8in57abn1fe8qfego0" 2025/02/13 21:37:45 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-zegicih0cola/rclone-sync-test-include/layer2" 2025/02/13 21:37:45 DEBUG : Creating backend with remote "TestDrive:crypt/acm2bl29gbtuhl9b1qh375055t9lo9mvu40inkr1thg9c16mrlrg/khf2vlblvnbf9ftevqm0htmss73hj1j5a7q328e4ohrgs7e2loe0/n01jpl9202nn9ec1rb75h0f1c4" 2025/02/13 21:37:48 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-zegicih0cola/rclone-sync-test-ignore-file" 2025/02/13 21:37:49 DEBUG : Creating backend with remote "TestDrive:crypt/acm2bl29gbtuhl9b1qh375055t9lo9mvu40inkr1thg9c16mrlrg/kmf11jujl9uha3tjganvgpkn45bu778hb5vb5riug1c26b38k7sg" 2025/02/13 21:37:52 DEBUG : rclone-sync-test-ignore-file/.ignore: md5 = 0757fa193338176b6e2017ad57f1c025 OK 2025/02/13 21:37:53 DEBUG : rclone-sync-test-ignore-file: Excluded 2025/02/13 21:37:54 DEBUG : rclone-sync-test: Excluded 2025/02/13 21:37:54 DEBUG : Added delayed dir = "rclone-sync-test-include", newDst= 2025/02/13 21:37:54 DEBUG : rclone-sync-test-include/layer2: Excluded 2025/02/13 21:37:54 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zegicih0cola/rclone-sync-test': Waiting for checks to finish 2025/02/13 21:37:54 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zegicih0cola/rclone-sync-test': Waiting for transfers to finish 2025/02/13 21:37:54 DEBUG : Waiting for deletions to finish 2025/02/13 21:37:54 INFO : There was nothing to transfer 2025/02/13 21:37:55 DEBUG : rclone-sync-test-ignore-file: Excluded 2025/02/13 21:37:56 DEBUG : rclone-sync-test: Excluded 2025/02/13 21:37:56 DEBUG : rclone-sync-test-include/layer2: Excluded 2025/02/13 21:37:56 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zegicih0cola': Waiting for checks to finish 2025/02/13 21:37:56 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zegicih0cola': Waiting for transfers to finish 2025/02/13 21:37:56 DEBUG : Waiting for deletions to finish 2025/02/13 21:37:56 INFO : rclone-sync-test-include: Removing directory 2025/02/13 21:37:56 DEBUG : khf2vlblvnbf9ftevqm0htmss73hj1j5a7q328e4ohrgs7e2loe0: Rmdir: contains file: "n01jpl9202nn9ec1rb75h0f1c4" 2025/02/13 21:37:56 DEBUG : rclone-sync-test-include: Failed to Rmdir: directory not empty 2025/02/13 21:37:56 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zegicih0cola': failed to delete 1 directories 2025/02/13 21:37:56 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zegicih0cola'", Local "Local file system at /tmp/rclone3758268997", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zegicih0cola'", Local "Local file system at /tmp/rclone3758268997", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zegicih0cola'", Local "Local file system at /tmp/rclone3758268997", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zegicih0cola'", Local "Local file system at /tmp/rclone3758268997", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zegicih0cola'", Local "Local file system at /tmp/rclone3758268997", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zegicih0cola'", Local "Local file system at /tmp/rclone3758268997", Modify Window "1ms" 2025/02/13 21:37:57 DEBUG : rclone-sync-test-ignore-file: Excluded 2025/02/13 21:37:58 DEBUG : rclone-sync-test: Excluded 2025/02/13 21:37:58 DEBUG : Added delayed dir = "rclone-sync-test-include", newDst= 2025/02/13 21:37:58 DEBUG : rclone-sync-test-include/layer2: Excluded 2025/02/13 21:37:58 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zegicih0cola/rclone-sync-test-include/layer2': Waiting for checks to finish 2025/02/13 21:37:58 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zegicih0cola/rclone-sync-test-include/layer2': Waiting for transfers to finish 2025/02/13 21:37:58 DEBUG : Waiting for deletions to finish 2025/02/13 21:37:58 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zegicih0cola'", Local "Local file system at /tmp/rclone3758268997", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zegicih0cola'", Local "Local file system at /tmp/rclone3758268997", Modify Window "1ms" 2025/02/13 21:37:59 DEBUG : rclone-sync-test-ignore-file: Excluded 2025/02/13 21:37:59 DEBUG : rclone-sync-test: Excluded 2025/02/13 21:38:00 DEBUG : rclone-sync-test-include/layer2: Excluded 2025/02/13 21:38:00 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zegicih0cola': Waiting for checks to finish 2025/02/13 21:38:00 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zegicih0cola': Waiting for transfers to finish 2025/02/13 21:38:00 DEBUG : Waiting for deletions to finish 2025/02/13 21:38:00 INFO : rclone-sync-test-include: Removing directory 2025/02/13 21:38:00 DEBUG : khf2vlblvnbf9ftevqm0htmss73hj1j5a7q328e4ohrgs7e2loe0: Rmdir: contains file: "n01jpl9202nn9ec1rb75h0f1c4" 2025/02/13 21:38:00 DEBUG : rclone-sync-test-include: Failed to Rmdir: directory not empty 2025/02/13 21:38:00 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zegicih0cola': failed to delete 1 directories 2025/02/13 21:38:00 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zegicih0cola'", Local "Local file system at /tmp/rclone3758268997", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zegicih0cola'", Local "Local file system at /tmp/rclone3758268997", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zegicih0cola'", Local "Local file system at /tmp/rclone3758268997", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zegicih0cola'", Local "Local file system at /tmp/rclone3758268997", Modify Window "1ms" 2025/02/13 21:38:01 DEBUG : : Excluded 2025/02/13 21:38:01 DEBUG : rclone-sync-test-ignore-file: Excluded 2025/02/13 21:38:01 DEBUG : rclone-sync-test: Excluded 2025/02/13 21:38:01 DEBUG : Added delayed dir = "rclone-sync-test-include", newDst= 2025/02/13 21:38:02 DEBUG : rclone-sync-test-include/layer2: Excluded 2025/02/13 21:38:02 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zegicih0cola/rclone-sync-test-ignore-file': Waiting for checks to finish 2025/02/13 21:38:02 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zegicih0cola/rclone-sync-test-ignore-file': Waiting for transfers to finish 2025/02/13 21:38:02 DEBUG : Waiting for deletions to finish 2025/02/13 21:38:02 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zegicih0cola'", Local "Local file system at /tmp/rclone3758268997", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zegicih0cola'", Local "Local file system at /tmp/rclone3758268997", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zegicih0cola'", Local "Local file system at /tmp/rclone3758268997", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zegicih0cola'", Local "Local file system at /tmp/rclone3758268997", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zegicih0cola'", Local "Local file system at /tmp/rclone3758268997", Modify Window "1ms" 2025/02/13 21:38:04 DEBUG : khf2vlblvnbf9ftevqm0htmss73hj1j5a7q328e4ohrgs7e2loe0: Rmdir: contains trashed file: "n01jpl9202nn9ec1rb75h0f1c4" 2025/02/13 21:38:05 DEBUG : kmf11jujl9uha3tjganvgpkn45bu778hb5vb5riug1c26b38k7sg: Rmdir: contains trashed file: "i0t74httmdlljg425j6tg570d8" --- PASS: TestSyncOverlapWithFilter (31.50s) === RUN TestSyncCompareDest run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zegicih0cola'", Local "Local file system at /tmp/rclone3758268997", Modify Window "1ms" 2025/02/13 21:38:14 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-zegicih0cola/dst" 2025/02/13 21:38:14 DEBUG : Creating backend with remote "TestDrive:crypt/acm2bl29gbtuhl9b1qh375055t9lo9mvu40inkr1thg9c16mrlrg/31u3jie661vd5p8j7rtc3hgbh0" 2025/02/13 21:38:15 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-zegicih0cola/CompareDest" 2025/02/13 21:38:15 DEBUG : Creating backend with remote "TestDrive:crypt/acm2bl29gbtuhl9b1qh375055t9lo9mvu40inkr1thg9c16mrlrg/gveqi14airsml4bgu7krj116o8" 2025/02/13 21:38:17 DEBUG : one: Need to transfer - File not found at Destination 2025/02/13 21:38:17 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zegicih0cola/dst': Waiting for checks to finish 2025/02/13 21:38:17 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zegicih0cola/dst': Waiting for transfers to finish 2025/02/13 21:38:20 DEBUG : one: md5 = efb567897fd9bc94940da310e174b04b OK 2025/02/13 21:38:20 INFO : one: Copied (new) 2025/02/13 21:38:20 DEBUG : Waiting for deletions to finish 2025/02/13 21:38:21 DEBUG : one: Sizes differ (src 5 vs dst 3) 2025/02/13 21:38:21 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zegicih0cola/dst': Waiting for checks to finish 2025/02/13 21:38:21 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zegicih0cola/dst': Waiting for transfers to finish 2025/02/13 21:38:22 DEBUG : one: md5 = fd27e9cd71b293a1bbedaecba92dc8d2 OK 2025/02/13 21:38:22 INFO : one: Copied (replaced existing) 2025/02/13 21:38:22 DEBUG : Waiting for deletions to finish 2025/02/13 21:38:24 DEBUG : dst/one: md5 = 30265af063002337eb7879ad085fa1e5 OK 2025/02/13 21:38:26 DEBUG : CompareDest/one: md5 = e6b41830873b9e93c3124e1aa2e6d3ee OK 2025/02/13 21:38:27 DEBUG : one: Sizes differ (src 5 vs dst 3) 2025/02/13 21:38:27 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zegicih0cola/dst': Waiting for checks to finish 2025/02/13 21:38:28 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/02/13 21:38:28 DEBUG : one: Destination found in --compare-dest, skipping 2025/02/13 21:38:28 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zegicih0cola/dst': Waiting for transfers to finish 2025/02/13 21:38:28 DEBUG : Waiting for deletions to finish 2025/02/13 21:38:28 INFO : There was nothing to transfer 2025/02/13 21:38:29 DEBUG : CompareDest/two: md5 = 3f2630e63b0e432334a9c93e4073f3bc OK 2025/02/13 21:38:30 DEBUG : two: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/02/13 21:38:30 DEBUG : two: Destination found in --compare-dest, skipping 2025/02/13 21:38:30 DEBUG : one: Sizes differ (src 5 vs dst 3) 2025/02/13 21:38:30 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zegicih0cola/dst': Waiting for checks to finish 2025/02/13 21:38:31 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/02/13 21:38:31 DEBUG : one: Destination found in --compare-dest, skipping 2025/02/13 21:38:31 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zegicih0cola/dst': Waiting for transfers to finish 2025/02/13 21:38:31 DEBUG : Waiting for deletions to finish 2025/02/13 21:38:31 INFO : There was nothing to transfer 2025/02/13 21:38:32 DEBUG : two: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/02/13 21:38:32 DEBUG : two: Destination found in --compare-dest, skipping 2025/02/13 21:38:32 DEBUG : one: Sizes differ (src 5 vs dst 3) 2025/02/13 21:38:32 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zegicih0cola/dst': Waiting for checks to finish 2025/02/13 21:38:32 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/02/13 21:38:32 DEBUG : one: Destination found in --compare-dest, skipping 2025/02/13 21:38:32 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zegicih0cola/dst': Waiting for transfers to finish 2025/02/13 21:38:32 DEBUG : Waiting for deletions to finish 2025/02/13 21:38:32 INFO : There was nothing to transfer sync_test.go:2175: No hash on uploaded file so skipping compare timestamp test 2025/02/13 21:38:34 DEBUG : two: Sizes differ (src 5 vs dst 3) 2025/02/13 21:38:34 DEBUG : two: Need to transfer - File not found at Destination 2025/02/13 21:38:34 DEBUG : one: Sizes differ (src 5 vs dst 3) 2025/02/13 21:38:34 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zegicih0cola/dst': Waiting for checks to finish 2025/02/13 21:38:34 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/02/13 21:38:34 DEBUG : one: Destination found in --compare-dest, skipping 2025/02/13 21:38:34 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zegicih0cola/dst': Waiting for transfers to finish 2025/02/13 21:38:35 DEBUG : two: md5 = a328f4e999f219c82958c86735c638d6 OK 2025/02/13 21:38:35 INFO : two: Copied (new) 2025/02/13 21:38:35 DEBUG : Waiting for deletions to finish 2025/02/13 21:38:39 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k" 2025/02/13 21:38:39 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" 2025/02/13 21:38:40 DEBUG : gveqi14airsml4bgu7krj116o8: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" 2025/02/13 21:38:40 DEBUG : gveqi14airsml4bgu7krj116o8: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k" --- PASS: TestSyncCompareDest (26.58s) === RUN TestSyncMultipleCompareDest run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zegicih0cola'", Local "Local file system at /tmp/rclone3758268997", Modify Window "1ms" 2025/02/13 21:38:43 DEBUG : pre-dest1/1: md5 = 3fe2143d7c687ca1d13ff1cd6e2099cb OK 2025/02/13 21:38:45 DEBUG : pre-dest2/2: md5 = e07531d74c8477be17979f0d0da26632 OK 2025/02/13 21:38:45 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-zegicih0cola/dest" 2025/02/13 21:38:45 DEBUG : Creating backend with remote "TestDrive:crypt/acm2bl29gbtuhl9b1qh375055t9lo9mvu40inkr1thg9c16mrlrg/rg03c1jvnehrrc617i0lnqjddc" 2025/02/13 21:38:47 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-zegicih0cola/pre-dest1" 2025/02/13 21:38:47 DEBUG : Creating backend with remote "TestDrive:crypt/acm2bl29gbtuhl9b1qh375055t9lo9mvu40inkr1thg9c16mrlrg/bbnblvh6k061ssopqrp18kd7gc" 2025/02/13 21:38:48 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-zegicih0cola/pre-dest2" 2025/02/13 21:38:48 DEBUG : Creating backend with remote "TestDrive:crypt/acm2bl29gbtuhl9b1qh375055t9lo9mvu40inkr1thg9c16mrlrg/dgicm1h6b5ejvlltm8eeif0bnk" 2025/02/13 21:38:49 DEBUG : 1: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/02/13 21:38:49 DEBUG : 1: Destination found in --compare-dest, skipping 2025/02/13 21:38:49 DEBUG : 2: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/02/13 21:38:49 DEBUG : 2: Destination found in --compare-dest, skipping 2025/02/13 21:38:50 DEBUG : 3: Need to transfer - File not found at Destination 2025/02/13 21:38:50 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zegicih0cola/dest': Waiting for checks to finish 2025/02/13 21:38:50 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zegicih0cola/dest': Waiting for transfers to finish 2025/02/13 21:38:52 DEBUG : 3: md5 = a69840ddfce7520fc742df2107324dda OK 2025/02/13 21:38:52 INFO : 3: Copied (new) 2025/02/13 21:38:52 DEBUG : Waiting for deletions to finish 2025/02/13 21:38:55 DEBUG : dgicm1h6b5ejvlltm8eeif0bnk: Rmdir: contains trashed file: "1ghu8geql9vrl726n32nrf65bc" 2025/02/13 21:38:56 DEBUG : bbnblvh6k061ssopqrp18kd7gc: Rmdir: contains trashed file: "skbfko3oil7es0lj68ob574sro" 2025/02/13 21:38:56 DEBUG : rg03c1jvnehrrc617i0lnqjddc: Rmdir: contains trashed file: "g072p7hmjchlnj0gibe64c1epg" --- PASS: TestSyncMultipleCompareDest (16.45s) === RUN TestSyncCopyDest run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zegicih0cola'", Local "Local file system at /tmp/rclone3758268997", Modify Window "1ms" 2025/02/13 21:38:57 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-zegicih0cola/dst" 2025/02/13 21:38:57 DEBUG : Creating backend with remote "TestDrive:crypt/acm2bl29gbtuhl9b1qh375055t9lo9mvu40inkr1thg9c16mrlrg/31u3jie661vd5p8j7rtc3hgbh0" 2025/02/13 21:38:59 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-zegicih0cola/CopyDest" 2025/02/13 21:38:59 DEBUG : Creating backend with remote "TestDrive:crypt/acm2bl29gbtuhl9b1qh375055t9lo9mvu40inkr1thg9c16mrlrg/d09o6po3f7bm6ce32vdgs8h9ls" 2025/02/13 21:39:01 DEBUG : one: Need to transfer - File not found at Destination 2025/02/13 21:39:01 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zegicih0cola/dst': Waiting for checks to finish 2025/02/13 21:39:01 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zegicih0cola/dst': Waiting for transfers to finish 2025/02/13 21:39:03 DEBUG : one: md5 = b39774f2015059e9c1acda3a98524e71 OK 2025/02/13 21:39:03 INFO : one: Copied (new) 2025/02/13 21:39:03 DEBUG : Waiting for deletions to finish 2025/02/13 21:39:04 DEBUG : one: Sizes differ (src 5 vs dst 3) 2025/02/13 21:39:04 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zegicih0cola/dst': Waiting for checks to finish 2025/02/13 21:39:04 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zegicih0cola/dst': Waiting for transfers to finish 2025/02/13 21:39:05 DEBUG : one: md5 = daf391ff05a169dea388ea76e909c751 OK 2025/02/13 21:39:05 INFO : one: Copied (replaced existing) 2025/02/13 21:39:05 DEBUG : Waiting for deletions to finish 2025/02/13 21:39:07 DEBUG : dst/one: md5 = 4ab937a8774863a5f7f314109c92fa7d OK 2025/02/13 21:39:09 DEBUG : CopyDest/one: md5 = 026ccd6298f74da5286189f37fcf265d OK 2025/02/13 21:39:10 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-zegicih0cola/BackupDir" 2025/02/13 21:39:10 DEBUG : Creating backend with remote "TestDrive:crypt/acm2bl29gbtuhl9b1qh375055t9lo9mvu40inkr1thg9c16mrlrg/s6dbk3lfi7c9kfvo6j7bla9m0g" 2025/02/13 21:39:12 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zegicih0cola/dst': Waiting for checks to finish 2025/02/13 21:39:12 DEBUG : one: Sizes differ (src 5 vs dst 3) 2025/02/13 21:39:13 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/02/13 21:39:13 DEBUG : one: Sizes differ (src 5 vs dst 3) 2025/02/13 21:39:14 INFO : one: Moved (server-side) 2025/02/13 21:39:15 INFO : one: Copied (server-side copy) 2025/02/13 21:39:15 DEBUG : one: Destination found in --copy-dest, using server-side copy 2025/02/13 21:39:15 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zegicih0cola/dst': Waiting for transfers to finish 2025/02/13 21:39:15 DEBUG : Waiting for deletions to finish 2025/02/13 21:39:17 DEBUG : CopyDest/two: md5 = 6633b5ce16aaf140a391d411696fbc93 OK 2025/02/13 21:39:18 DEBUG : two: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/02/13 21:39:19 INFO : two: Copied (server-side copy) 2025/02/13 21:39:19 DEBUG : two: Destination found in --copy-dest, using server-side copy 2025/02/13 21:39:19 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/02/13 21:39:19 DEBUG : one: Unchanged skipping 2025/02/13 21:39:19 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zegicih0cola/dst': Waiting for checks to finish 2025/02/13 21:39:19 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zegicih0cola/dst': Waiting for transfers to finish 2025/02/13 21:39:19 DEBUG : Waiting for deletions to finish 2025/02/13 21:39:20 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/02/13 21:39:20 DEBUG : one: Unchanged skipping 2025/02/13 21:39:20 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zegicih0cola/dst': Waiting for checks to finish 2025/02/13 21:39:20 DEBUG : two: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/02/13 21:39:20 DEBUG : two: Unchanged skipping 2025/02/13 21:39:20 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zegicih0cola/dst': Waiting for transfers to finish 2025/02/13 21:39:20 DEBUG : Waiting for deletions to finish 2025/02/13 21:39:20 INFO : There was nothing to transfer 2025/02/13 21:39:22 DEBUG : CopyDest/three: md5 = adfe9bf688af310476168c57ad0b7761 OK 2025/02/13 21:39:23 DEBUG : three: Sizes differ (src 7 vs dst 5) 2025/02/13 21:39:23 DEBUG : three: Destination not found in --copy-dest 2025/02/13 21:39:23 DEBUG : three: Need to transfer - File not found at Destination 2025/02/13 21:39:23 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/02/13 21:39:23 DEBUG : one: Unchanged skipping 2025/02/13 21:39:23 DEBUG : two: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/02/13 21:39:23 DEBUG : two: Unchanged skipping 2025/02/13 21:39:23 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zegicih0cola/dst': Waiting for checks to finish 2025/02/13 21:39:23 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zegicih0cola/dst': Waiting for transfers to finish 2025/02/13 21:39:24 DEBUG : three: md5 = 4c250d4a638234d1b98b19e27bc60c15 OK 2025/02/13 21:39:24 INFO : three: Copied (new) 2025/02/13 21:39:24 DEBUG : Waiting for deletions to finish 2025/02/13 21:39:29 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "b6jdmn2b1adrhc8vikh7edr9os" 2025/02/13 21:39:29 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k" 2025/02/13 21:39:29 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" 2025/02/13 21:39:30 DEBUG : d09o6po3f7bm6ce32vdgs8h9ls: Rmdir: contains trashed file: "b6jdmn2b1adrhc8vikh7edr9os" 2025/02/13 21:39:30 DEBUG : d09o6po3f7bm6ce32vdgs8h9ls: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k" 2025/02/13 21:39:30 DEBUG : d09o6po3f7bm6ce32vdgs8h9ls: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" 2025/02/13 21:39:31 DEBUG : s6dbk3lfi7c9kfvo6j7bla9m0g: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" --- PASS: TestSyncCopyDest (34.34s) === RUN TestSyncBackupDir run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zegicih0cola'", Local "Local file system at /tmp/rclone3758268997", Modify Window "1ms" 2025/02/13 21:39:33 DEBUG : dst/one: md5 = deb50b68fc3b083b20f61195ba44a5f6 OK 2025/02/13 21:39:35 DEBUG : dst/two: md5 = d12a43c3f4c71a8af02a8f86d0f3dc60 OK 2025/02/13 21:39:36 DEBUG : dst/three.txt: md5 = c088ba4f8f98fa6bbd504396fce2596b OK 2025/02/13 21:39:37 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-zegicih0cola/dst" 2025/02/13 21:39:37 DEBUG : Creating backend with remote "TestDrive:crypt/acm2bl29gbtuhl9b1qh375055t9lo9mvu40inkr1thg9c16mrlrg/31u3jie661vd5p8j7rtc3hgbh0" 2025/02/13 21:39:37 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-zegicih0cola/backup" 2025/02/13 21:39:38 DEBUG : Creating backend with remote "TestDrive:crypt/acm2bl29gbtuhl9b1qh375055t9lo9mvu40inkr1thg9c16mrlrg/1nrff024r7pq65ecp72fc28jb0" 2025/02/13 21:39:40 DEBUG : one: Sizes differ (src 4 vs dst 3) 2025/02/13 21:39:40 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/02/13 21:39:40 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zegicih0cola/dst': Waiting for checks to finish 2025/02/13 21:39:40 DEBUG : two: Unchanged skipping 2025/02/13 21:39:41 INFO : one: Moved (server-side) 2025/02/13 21:39:41 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zegicih0cola/dst': Waiting for transfers to finish 2025/02/13 21:39:43 DEBUG : one: md5 = 21de876743a545c1453801d462cec3d4 OK 2025/02/13 21:39:43 INFO : one: Copied (new) 2025/02/13 21:39:43 DEBUG : Waiting for deletions to finish 2025/02/13 21:39:44 INFO : three.txt: Moved (server-side) 2025/02/13 21:39:44 INFO : three.txt: Moved into backup dir 2025/02/13 21:39:46 DEBUG : dst/three.txt: md5 = 3b9ebfc34891cc4add5fc995fc6d0955 OK 2025/02/13 21:39:46 DEBUG : one: Sizes differ (src 5 vs dst 4) 2025/02/13 21:39:46 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/02/13 21:39:46 DEBUG : two: Unchanged skipping 2025/02/13 21:39:46 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zegicih0cola/dst': Waiting for checks to finish 2025/02/13 21:39:47 INFO : one: Deleted 2025/02/13 21:39:48 INFO : one: Moved (server-side) 2025/02/13 21:39:48 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zegicih0cola/dst': Waiting for transfers to finish 2025/02/13 21:39:49 DEBUG : one: md5 = 6627841c2ca220d148471cad823de854 OK 2025/02/13 21:39:49 INFO : one: Copied (new) 2025/02/13 21:39:49 DEBUG : Waiting for deletions to finish 2025/02/13 21:39:49 INFO : three.txt: Deleted 2025/02/13 21:39:50 INFO : three.txt: Moved (server-side) 2025/02/13 21:39:50 INFO : three.txt: Moved into backup dir 2025/02/13 21:39:53 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" 2025/02/13 21:39:53 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k" 2025/02/13 21:39:54 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" 2025/02/13 21:39:54 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "tr2hj63d80ftlmvm6a952snjcc" 2025/02/13 21:39:54 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" 2025/02/13 21:39:54 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "tr2hj63d80ftlmvm6a952snjcc" --- PASS: TestSyncBackupDir (23.27s) === RUN TestSyncBackupDirWithSuffix run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zegicih0cola'", Local "Local file system at /tmp/rclone3758268997", Modify Window "1ms" 2025/02/13 21:39:57 DEBUG : dst/one: md5 = 2ffc6bfe1df10ba1613cb027b176668f OK 2025/02/13 21:39:58 DEBUG : dst/two: md5 = b57a573685a24bb91a9f515a13f5154e OK 2025/02/13 21:39:59 DEBUG : dst/three.txt: md5 = 24b0ef8be14ad37509c5a2e2a6db7de0 OK 2025/02/13 21:40:00 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-zegicih0cola/dst" 2025/02/13 21:40:00 DEBUG : Creating backend with remote "TestDrive:crypt/acm2bl29gbtuhl9b1qh375055t9lo9mvu40inkr1thg9c16mrlrg/31u3jie661vd5p8j7rtc3hgbh0" 2025/02/13 21:40:01 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-zegicih0cola/backup" 2025/02/13 21:40:01 DEBUG : Creating backend with remote "TestDrive:crypt/acm2bl29gbtuhl9b1qh375055t9lo9mvu40inkr1thg9c16mrlrg/1nrff024r7pq65ecp72fc28jb0" 2025/02/13 21:40:02 DEBUG : one: Sizes differ (src 4 vs dst 3) 2025/02/13 21:40:02 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zegicih0cola/dst': Waiting for checks to finish 2025/02/13 21:40:02 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/02/13 21:40:02 DEBUG : two: Unchanged skipping 2025/02/13 21:40:04 INFO : one: Moved (server-side) to: one.bak 2025/02/13 21:40:04 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zegicih0cola/dst': Waiting for transfers to finish 2025/02/13 21:40:05 DEBUG : one: md5 = a5002b5717cb57a20f27cd589e59072c OK 2025/02/13 21:40:05 INFO : one: Copied (new) 2025/02/13 21:40:05 DEBUG : Waiting for deletions to finish 2025/02/13 21:40:06 INFO : three.txt: Moved (server-side) to: three.txt.bak 2025/02/13 21:40:06 INFO : three.txt: Moved into backup dir 2025/02/13 21:40:08 DEBUG : dst/three.txt: md5 = 1744f299eab2b63730c73146d68e4b75 OK 2025/02/13 21:40:09 DEBUG : one: Sizes differ (src 5 vs dst 4) 2025/02/13 21:40:09 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zegicih0cola/dst': Waiting for checks to finish 2025/02/13 21:40:09 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/02/13 21:40:09 DEBUG : two: Unchanged skipping 2025/02/13 21:40:10 INFO : one.bak: Deleted 2025/02/13 21:40:10 INFO : one: Moved (server-side) to: one.bak 2025/02/13 21:40:10 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zegicih0cola/dst': Waiting for transfers to finish 2025/02/13 21:40:11 DEBUG : one: md5 = 423452936daa668a29c2a27a92e91613 OK 2025/02/13 21:40:11 INFO : one: Copied (new) 2025/02/13 21:40:11 DEBUG : Waiting for deletions to finish 2025/02/13 21:40:12 INFO : three.txt.bak: Deleted 2025/02/13 21:40:13 INFO : three.txt: Moved (server-side) to: three.txt.bak 2025/02/13 21:40:13 INFO : three.txt: Moved into backup dir 2025/02/13 21:40:15 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" 2025/02/13 21:40:15 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k" 2025/02/13 21:40:16 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "sk91qgsqfn0r271r2ehsaoc20c" 2025/02/13 21:40:16 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "qltcak2uaegtmcoa8vijdppbp8" 2025/02/13 21:40:16 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "sk91qgsqfn0r271r2ehsaoc20c" 2025/02/13 21:40:16 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "qltcak2uaegtmcoa8vijdppbp8" --- PASS: TestSyncBackupDirWithSuffix (22.18s) === RUN TestSyncBackupDirWithSuffixKeepExtension run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zegicih0cola'", Local "Local file system at /tmp/rclone3758268997", Modify Window "1ms" 2025/02/13 21:40:19 DEBUG : dst/one: md5 = 97ed5d4d4cffd0d7aa5373103f0b708c OK 2025/02/13 21:40:21 DEBUG : dst/two: md5 = 0ebf2c0388688d2fe74415578a25a49e OK 2025/02/13 21:40:22 DEBUG : dst/three.txt: md5 = 76f5324293214b62a39cc338b3037001 OK 2025/02/13 21:40:23 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-zegicih0cola/dst" 2025/02/13 21:40:23 DEBUG : Config file has changed externally - reloading 2025/02/13 21:40:23 DEBUG : Creating backend with remote "TestDrive:crypt/acm2bl29gbtuhl9b1qh375055t9lo9mvu40inkr1thg9c16mrlrg/31u3jie661vd5p8j7rtc3hgbh0" 2025/02/13 21:40:24 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-zegicih0cola/backup" 2025/02/13 21:40:24 DEBUG : Creating backend with remote "TestDrive:crypt/acm2bl29gbtuhl9b1qh375055t9lo9mvu40inkr1thg9c16mrlrg/1nrff024r7pq65ecp72fc28jb0" 2025/02/13 21:40:26 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zegicih0cola/dst': Waiting for checks to finish 2025/02/13 21:40:26 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/02/13 21:40:26 DEBUG : two: Unchanged skipping 2025/02/13 21:40:26 DEBUG : one: Sizes differ (src 4 vs dst 3) 2025/02/13 21:40:27 INFO : one: Moved (server-side) to: one-2019-01-01 2025/02/13 21:40:27 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zegicih0cola/dst': Waiting for transfers to finish 2025/02/13 21:40:29 DEBUG : one: md5 = dc4f37139f320cc23eea22da3d1344ae OK 2025/02/13 21:40:29 INFO : one: Copied (new) 2025/02/13 21:40:29 DEBUG : Waiting for deletions to finish 2025/02/13 21:40:29 INFO : three.txt: Moved (server-side) to: three-2019-01-01.txt 2025/02/13 21:40:29 INFO : three.txt: Moved into backup dir 2025/02/13 21:40:31 DEBUG : dst/three.txt: md5 = 1185e7dfcf9620ad3310b5c1959814c0 OK 2025/02/13 21:40:32 DEBUG : one: Sizes differ (src 5 vs dst 4) 2025/02/13 21:40:32 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/02/13 21:40:32 DEBUG : two: Unchanged skipping 2025/02/13 21:40:32 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zegicih0cola/dst': Waiting for checks to finish 2025/02/13 21:40:33 INFO : one-2019-01-01: Deleted 2025/02/13 21:40:33 INFO : one: Moved (server-side) to: one-2019-01-01 2025/02/13 21:40:33 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zegicih0cola/dst': Waiting for transfers to finish 2025/02/13 21:40:35 DEBUG : one: md5 = 88a663c40d646c10d05596651dc8f3de OK 2025/02/13 21:40:35 INFO : one: Copied (new) 2025/02/13 21:40:35 DEBUG : Waiting for deletions to finish 2025/02/13 21:40:36 INFO : three-2019-01-01.txt: Deleted 2025/02/13 21:40:36 INFO : three.txt: Moved (server-side) to: three-2019-01-01.txt 2025/02/13 21:40:36 INFO : three.txt: Moved into backup dir 2025/02/13 21:40:39 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" 2025/02/13 21:40:39 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k" 2025/02/13 21:40:40 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "qtq2f6qq4lgpsmj88vb7147qje3prudmtfdtr2342fth58vo9a50" 2025/02/13 21:40:40 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "jcjl1bv3ep0v8kt35lqql1co90" 2025/02/13 21:40:40 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "qtq2f6qq4lgpsmj88vb7147qje3prudmtfdtr2342fth58vo9a50" 2025/02/13 21:40:40 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "jcjl1bv3ep0v8kt35lqql1co90" --- PASS: TestSyncBackupDirWithSuffixKeepExtension (23.52s) === RUN TestSyncBackupDirSuffixOnly run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zegicih0cola'", Local "Local file system at /tmp/rclone3758268997", Modify Window "1ms" 2025/02/13 21:40:43 DEBUG : dst/one: md5 = dd20ee3ec29c7d2ddb41f95223e04367 OK 2025/02/13 21:40:44 DEBUG : dst/two: md5 = a30e59a55b992d6c6faee7b5eda55d9e OK 2025/02/13 21:40:45 DEBUG : dst/three.txt: md5 = 1d377c0c6dc974de57ecb7d6629e244c OK 2025/02/13 21:40:46 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-zegicih0cola/dst" 2025/02/13 21:40:46 DEBUG : Creating backend with remote "TestDrive:crypt/acm2bl29gbtuhl9b1qh375055t9lo9mvu40inkr1thg9c16mrlrg/31u3jie661vd5p8j7rtc3hgbh0" 2025/02/13 21:40:47 DEBUG : one: Sizes differ (src 4 vs dst 3) 2025/02/13 21:40:47 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/02/13 21:40:47 DEBUG : two: Unchanged skipping 2025/02/13 21:40:47 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zegicih0cola/dst': Waiting for checks to finish 2025/02/13 21:40:48 INFO : one: Moved (server-side) to: one.bak 2025/02/13 21:40:48 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zegicih0cola/dst': Waiting for transfers to finish 2025/02/13 21:40:49 DEBUG : one: md5 = 7690be46a9645544a52abbc9b1f73bfb OK 2025/02/13 21:40:49 INFO : one: Copied (new) 2025/02/13 21:40:49 DEBUG : Waiting for deletions to finish 2025/02/13 21:40:50 INFO : three.txt: Moved (server-side) to: three.txt.bak 2025/02/13 21:40:50 INFO : three.txt: Moved into backup dir 2025/02/13 21:40:52 DEBUG : dst/three.txt: md5 = 6799b9003c73cec8dfe7c283d87a5ca4 OK 2025/02/13 21:40:53 DEBUG : one.bak: Excluded (Path Filter) 2025/02/13 21:40:53 DEBUG : one.bak: Excluded 2025/02/13 21:40:53 DEBUG : three.txt.bak: Excluded (Path Filter) 2025/02/13 21:40:53 DEBUG : three.txt.bak: Excluded 2025/02/13 21:40:53 DEBUG : one: Sizes differ (src 5 vs dst 4) 2025/02/13 21:40:53 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/02/13 21:40:53 DEBUG : two: Unchanged skipping 2025/02/13 21:40:53 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zegicih0cola/dst': Waiting for checks to finish 2025/02/13 21:40:53 INFO : one.bak: Deleted 2025/02/13 21:40:54 INFO : one: Moved (server-side) to: one.bak 2025/02/13 21:40:54 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zegicih0cola/dst': Waiting for transfers to finish 2025/02/13 21:40:55 DEBUG : one: md5 = fa8e3fd57d79318e3fc6b63608caadfa OK 2025/02/13 21:40:55 INFO : one: Copied (new) 2025/02/13 21:40:55 DEBUG : Waiting for deletions to finish 2025/02/13 21:40:56 INFO : three.txt.bak: Deleted 2025/02/13 21:40:56 INFO : three.txt: Moved (server-side) to: three.txt.bak 2025/02/13 21:40:56 INFO : three.txt: Moved into backup dir 2025/02/13 21:41:00 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" 2025/02/13 21:41:00 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "sk91qgsqfn0r271r2ehsaoc20c" 2025/02/13 21:41:00 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "qltcak2uaegtmcoa8vijdppbp8" 2025/02/13 21:41:00 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "qltcak2uaegtmcoa8vijdppbp8" 2025/02/13 21:41:00 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "sk91qgsqfn0r271r2ehsaoc20c" 2025/02/13 21:41:00 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k" --- PASS: TestSyncBackupDirSuffixOnly (19.92s) === RUN TestSyncSuffix run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zegicih0cola'", Local "Local file system at /tmp/rclone3758268997", Modify Window "1ms" 2025/02/13 21:41:02 DEBUG : dst/one: md5 = 1341324163e2cd9b021c98af9f6501eb OK 2025/02/13 21:41:04 DEBUG : dst/two: md5 = 5530813a5250e64759b623d06bdc4f40 OK 2025/02/13 21:41:05 DEBUG : dst/three.txt: md5 = 93f9dec52374da5f87b0941cf8e6272f OK 2025/02/13 21:41:06 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-zegicih0cola/dst" 2025/02/13 21:41:06 DEBUG : Creating backend with remote "TestDrive:crypt/acm2bl29gbtuhl9b1qh375055t9lo9mvu40inkr1thg9c16mrlrg/31u3jie661vd5p8j7rtc3hgbh0" 2025/02/13 21:41:07 DEBUG : one: Sizes differ (src 4 vs dst 3) 2025/02/13 21:41:07 INFO : one: Moved (server-side) to: one.bak 2025/02/13 21:41:09 DEBUG : one: md5 = 83fd1e2ee6ef28fe581b400e561857c8 OK 2025/02/13 21:41:09 INFO : one: Copied (new) 2025/02/13 21:41:09 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/02/13 21:41:09 DEBUG : two: Unchanged skipping 2025/02/13 21:41:09 DEBUG : three.txt: Sizes differ (src 6 vs dst 5) 2025/02/13 21:41:10 INFO : three.txt: Moved (server-side) to: three.txt.bak 2025/02/13 21:41:11 DEBUG : three.txt: md5 = 03e3a7ed0cd3d7d01656fb7eb15764f2 OK 2025/02/13 21:41:11 INFO : three.txt: Copied (new) 2025/02/13 21:41:13 DEBUG : one: Sizes differ (src 5 vs dst 4) 2025/02/13 21:41:13 INFO : one.bak: Deleted 2025/02/13 21:41:14 INFO : one: Moved (server-side) to: one.bak 2025/02/13 21:41:15 DEBUG : one: md5 = fec5632643f8a27a8025b71f10bf0f52 OK 2025/02/13 21:41:15 INFO : one: Copied (new) 2025/02/13 21:41:15 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/02/13 21:41:15 DEBUG : two: Unchanged skipping 2025/02/13 21:41:16 DEBUG : three.txt: Sizes differ (src 19 vs dst 6) 2025/02/13 21:41:16 INFO : three.txt.bak: Deleted 2025/02/13 21:41:17 INFO : three.txt: Moved (server-side) to: three.txt.bak 2025/02/13 21:41:18 DEBUG : three.txt: md5 = 6356a4dcfd012511ff8d47896e430317 OK 2025/02/13 21:41:18 INFO : three.txt: Copied (new) 2025/02/13 21:41:22 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "tr2hj63d80ftlmvm6a952snjcc" 2025/02/13 21:41:22 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" 2025/02/13 21:41:22 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "qltcak2uaegtmcoa8vijdppbp8" 2025/02/13 21:41:22 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "sk91qgsqfn0r271r2ehsaoc20c" 2025/02/13 21:41:22 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "qltcak2uaegtmcoa8vijdppbp8" 2025/02/13 21:41:22 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k" 2025/02/13 21:41:22 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "sk91qgsqfn0r271r2ehsaoc20c" --- PASS: TestSyncSuffix (22.29s) === RUN TestSyncSuffixKeepExtension run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zegicih0cola'", Local "Local file system at /tmp/rclone3758268997", Modify Window "1ms" 2025/02/13 21:41:25 DEBUG : dst/one: md5 = 885ea258c488e18bf889988297ba0a93 OK 2025/02/13 21:41:26 DEBUG : dst/two: md5 = 1faa40424555950d515ab86be5984d67 OK 2025/02/13 21:41:27 DEBUG : dst/three.txt: md5 = 1a7b8f21c75437c0b42aa80dd3269e2b OK 2025/02/13 21:41:28 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-zegicih0cola/dst" 2025/02/13 21:41:28 DEBUG : Creating backend with remote "TestDrive:crypt/acm2bl29gbtuhl9b1qh375055t9lo9mvu40inkr1thg9c16mrlrg/31u3jie661vd5p8j7rtc3hgbh0" 2025/02/13 21:41:29 DEBUG : one: Sizes differ (src 4 vs dst 3) 2025/02/13 21:41:30 INFO : one: Moved (server-side) to: one-2019-01-01 2025/02/13 21:41:31 DEBUG : one: md5 = 7fc7c30841bcadebb9be12933fa9f035 OK 2025/02/13 21:41:31 INFO : one: Copied (new) 2025/02/13 21:41:31 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/02/13 21:41:31 DEBUG : two: Unchanged skipping 2025/02/13 21:41:31 DEBUG : three.txt: Sizes differ (src 6 vs dst 5) 2025/02/13 21:41:32 INFO : three.txt: Moved (server-side) to: three-2019-01-01.txt 2025/02/13 21:41:34 DEBUG : three.txt: md5 = cd3cbca07ad3d1a6dabd0e0d9e83b358 OK 2025/02/13 21:41:34 INFO : three.txt: Copied (new) 2025/02/13 21:41:35 DEBUG : one: Sizes differ (src 5 vs dst 4) 2025/02/13 21:41:36 INFO : one-2019-01-01: Deleted 2025/02/13 21:41:36 INFO : one: Moved (server-side) to: one-2019-01-01 2025/02/13 21:41:38 DEBUG : one: md5 = 7321b443f9bc07d19aaee8e1111f3b83 OK 2025/02/13 21:41:38 INFO : one: Copied (new) 2025/02/13 21:41:38 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/02/13 21:41:38 DEBUG : two: Unchanged skipping 2025/02/13 21:41:38 DEBUG : three.txt: Sizes differ (src 19 vs dst 6) 2025/02/13 21:41:39 INFO : three-2019-01-01.txt: Deleted 2025/02/13 21:41:39 INFO : three.txt: Moved (server-side) to: three-2019-01-01.txt 2025/02/13 21:41:41 DEBUG : three.txt: md5 = f57fa2f7c1912607a8323e609fc9a83e OK 2025/02/13 21:41:41 INFO : three.txt: Copied (new) 2025/02/13 21:41:44 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "tr2hj63d80ftlmvm6a952snjcc" 2025/02/13 21:41:44 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" 2025/02/13 21:41:44 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "jcjl1bv3ep0v8kt35lqql1co90" 2025/02/13 21:41:44 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "jcjl1bv3ep0v8kt35lqql1co90" 2025/02/13 21:41:44 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k" 2025/02/13 21:41:44 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "qtq2f6qq4lgpsmj88vb7147qje3prudmtfdtr2342fth58vo9a50" 2025/02/13 21:41:44 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "qtq2f6qq4lgpsmj88vb7147qje3prudmtfdtr2342fth58vo9a50" --- PASS: TestSyncSuffixKeepExtension (22.59s) === RUN TestSyncUTFNorm run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zegicih0cola'", Local "Local file system at /tmp/rclone3758268997", Modify Window "1ms" 2025/02/13 21:41:46 DEBUG : Testêé: md5 = 36069648243a6a7f15a1accb4fe20069 OK 2025/02/13 21:41:47 DEBUG : Testêé: Sizes differ (src 14 vs dst 18) 2025/02/13 21:41:47 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zegicih0cola': Waiting for checks to finish 2025/02/13 21:41:47 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zegicih0cola': Waiting for transfers to finish 2025/02/13 21:41:48 DEBUG : Testêé: md5 = b9822a67abd9e41f6dee721427a88222 OK 2025/02/13 21:41:48 INFO : Testêé: Copied (replaced existing) to: Testêé 2025/02/13 21:41:48 DEBUG : Waiting for deletions to finish --- PASS: TestSyncUTFNorm (4.29s) === RUN TestSyncImmutable run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zegicih0cola'", Local "Local file system at /tmp/rclone3758268997", Modify Window "1ms" 2025/02/13 21:41:50 DEBUG : existing: Need to transfer - File not found at Destination 2025/02/13 21:41:50 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zegicih0cola': Waiting for checks to finish 2025/02/13 21:41:50 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zegicih0cola': Waiting for transfers to finish 2025/02/13 21:41:51 DEBUG : existing: md5 = 4669b83d4cba84fcb3f3bdcd355ca3c9 OK 2025/02/13 21:41:51 INFO : existing: Copied (new) 2025/02/13 21:41:51 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zegicih0cola'", Local "Local file system at /tmp/rclone3758268997", Modify Window "1ms" 2025/02/13 21:41:52 DEBUG : existing: Sizes differ (src 8 vs dst 6) 2025/02/13 21:41:52 ERROR : existing: Source and destination exist but do not match: immutable file modified 2025/02/13 21:41:52 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zegicih0cola': Waiting for checks to finish 2025/02/13 21:41:52 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zegicih0cola': Waiting for transfers to finish 2025/02/13 21:41:52 ERROR : Encrypted drive 'TestCryptDrive:rclone-test-zegicih0cola': not deleting files as there were IO errors 2025/02/13 21:41:52 ERROR : Encrypted drive 'TestCryptDrive:rclone-test-zegicih0cola': not deleting directories as there were IO errors run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zegicih0cola'", Local "Local file system at /tmp/rclone3758268997", Modify Window "1ms" --- PASS: TestSyncImmutable (4.69s) === RUN TestSyncIgnoreCase run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zegicih0cola'", Local "Local file system at /tmp/rclone3758268997", Modify Window "1ms" 2025/02/13 21:41:56 DEBUG : EXISTING: md5 = a551c13106a81ebb145838993ac4db7f OK 2025/02/13 21:41:56 DEBUG : existing: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/02/13 21:41:56 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zegicih0cola': Waiting for checks to finish 2025/02/13 21:41:56 DEBUG : existing: Unchanged skipping 2025/02/13 21:41:56 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zegicih0cola': Waiting for transfers to finish 2025/02/13 21:41:56 DEBUG : Waiting for deletions to finish 2025/02/13 21:41:56 INFO : There was nothing to transfer --- PASS: TestSyncIgnoreCase (3.42s) === RUN TestFixCase run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zegicih0cola'", Local "Local file system at /tmp/rclone3758268997", Modify Window "1ms" sync_test.go:2635: Skipping test as local or remote are case-sensitive --- SKIP: TestFixCase (0.49s) === RUN TestMaxTransfer === RUN TestMaxTransfer/Hard run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zegicih0cola'", Local "Local file system at /tmp/rclone3758268997", 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-zegicih0cola'", Local "Local file system at /tmp/rclone3758268997", 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-zegicih0cola'", Local "Local file system at /tmp/rclone3758268997", Modify Window "1ms" sync_test.go:2674: This test only runs on local --- PASS: TestMaxTransfer (1.41s) --- SKIP: TestMaxTransfer/Hard (0.49s) --- SKIP: TestMaxTransfer/Soft (0.45s) --- SKIP: TestMaxTransfer/Cautious (0.47s) === RUN TestSyncConcurrentDelete run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zegicih0cola'", Local "Local file system at /tmp/rclone3758268997", Modify Window "1ms" 2025/02/13 21:42:01 DEBUG : both0: md5 = 656b573ff2e5e64f4598c0a6d8c88389 OK 2025/02/13 21:42:02 DEBUG : only0: md5 = 30d7999c7832e72d1348847947e8a713 OK 2025/02/13 21:42:04 DEBUG : both1: md5 = 51e0f79a8e59bf8f046ddb660558551f OK 2025/02/13 21:42:05 DEBUG : only1: md5 = 4a8f626fd7f457791f0edacc5ecd6d8f OK 2025/02/13 21:42:06 DEBUG : both2: md5 = d2cf896bfa3ef4c03c76fbdfd4936aca OK 2025/02/13 21:42:08 DEBUG : only2: md5 = 3dd57b1c1bf970e7530d0f1ce2efcb77 OK 2025/02/13 21:42:09 DEBUG : both3: md5 = eefce5acd20bfa76fb627e1b01a45e11 OK 2025/02/13 21:42:10 DEBUG : only3: md5 = 78bdf636f5d336ec0da5d875e61d1500 OK 2025/02/13 21:42:12 DEBUG : both4: md5 = 3f4e1c8770d7c0c4a82269120db2a75b OK 2025/02/13 21:42:13 DEBUG : only4: md5 = b7d365594179f178cb23c96787922a4d OK 2025/02/13 21:42:14 DEBUG : both5: md5 = a418465ee255a13131e9413c42efe889 OK 2025/02/13 21:42:16 DEBUG : only5: md5 = 2fa235e9a289c5a0705ff2e6cbaebfa9 OK 2025/02/13 21:42:17 DEBUG : both6: md5 = d551282eff4fd79e040560360005046a OK 2025/02/13 21:42:19 DEBUG : only6: md5 = a66bfee620694772794cbb3cd80aafed OK 2025/02/13 21:42:20 DEBUG : both7: md5 = 035d41cf67e9983a62fdf0d78bb2900e OK 2025/02/13 21:42:21 DEBUG : only7: md5 = 9fc72522d508a94fd851f1abb126f338 OK 2025/02/13 21:42:23 DEBUG : both8: md5 = 2b6cbb6f2a8c6aac46767d87ddc47058 OK 2025/02/13 21:42:24 DEBUG : only8: md5 = db5e0923a1fe6c656e0d2b7c3bba3fa8 OK 2025/02/13 21:42:26 DEBUG : both9: md5 = a34a1be52f31fcac5558189161e89e69 OK 2025/02/13 21:42:27 DEBUG : only9: md5 = 4c32ea83899804a73a820d82f3cd2ef8 OK 2025/02/13 21:42:28 DEBUG : both10: md5 = 88af7b83cfbb47184a841c0ebae1b97f OK 2025/02/13 21:42:30 DEBUG : only10: md5 = 8ca0b7c98becb8977c4868892a2a81c3 OK 2025/02/13 21:42:31 DEBUG : both11: md5 = 0956b69af5f19259a5b29f1d28449002 OK 2025/02/13 21:42:33 DEBUG : only11: md5 = 538388d1018f44b3761ef4b9b3b8d19b OK 2025/02/13 21:42:34 DEBUG : both12: md5 = 5497d8781c76399d4bdfd75c9ae4802f OK 2025/02/13 21:42:35 DEBUG : only12: md5 = e64b6bff62be78d090f6dcf8efde709d OK 2025/02/13 21:42:37 DEBUG : both13: md5 = 624621c3c755b3bb2526e6f8846b32bb OK 2025/02/13 21:42:38 DEBUG : only13: md5 = f5f0098e60a8a64776006eaf3165a08c OK 2025/02/13 21:42:39 DEBUG : both14: md5 = 2e6067407c902656e48d970ee0439546 OK 2025/02/13 21:42:41 DEBUG : only14: md5 = 775c9f29a748d57b042437ae399eaa54 OK 2025/02/13 21:42:42 DEBUG : both15: md5 = 01dafeb8160980e84b765f24268aaefe OK 2025/02/13 21:42:43 DEBUG : only15: md5 = ab6463402882b554232a9826fbbb1609 OK 2025/02/13 21:42:44 DEBUG : both16: md5 = a99beadfb23afabe0c17289e2423c5a3 OK 2025/02/13 21:42:46 DEBUG : only16: md5 = be35ba366b634eb22bb6f6d5a6f7ea97 OK 2025/02/13 21:42:47 DEBUG : both17: md5 = a636d4923244356822b7b73de593549f OK 2025/02/13 21:42:49 DEBUG : only17: md5 = 2cb5200fc3b0a98b6992881b4e349099 OK 2025/02/13 21:42:50 DEBUG : both18: md5 = 12368178c2f7b2eeb182fdd18ecba693 OK 2025/02/13 21:42:51 DEBUG : only18: md5 = 2496d66f05cb3883dd25904dcfada9e7 OK 2025/02/13 21:42:53 DEBUG : both19: md5 = 75f6703a4c8294b346066c1e37df89da OK 2025/02/13 21:42:54 DEBUG : only19: md5 = ed0b926b898a2b911f943966886bd3d0 OK 2025/02/13 21:42:55 DEBUG : both1: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/02/13 21:42:55 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zegicih0cola': Waiting for checks to finish 2025/02/13 21:42:55 DEBUG : both10: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/02/13 21:42:55 DEBUG : both0: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/02/13 21:42:55 DEBUG : both11: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/02/13 21:42:55 DEBUG : both1: Unchanged skipping 2025/02/13 21:42:55 DEBUG : both12: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/02/13 21:42:55 DEBUG : both10: Unchanged skipping 2025/02/13 21:42:55 DEBUG : both13: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/02/13 21:42:55 DEBUG : both13: Unchanged skipping 2025/02/13 21:42:55 DEBUG : both14: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/02/13 21:42:55 DEBUG : both14: Unchanged skipping 2025/02/13 21:42:55 DEBUG : both15: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/02/13 21:42:55 DEBUG : both15: Unchanged skipping 2025/02/13 21:42:55 DEBUG : both16: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/02/13 21:42:55 DEBUG : both0: Unchanged skipping 2025/02/13 21:42:55 DEBUG : both17: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/02/13 21:42:55 DEBUG : both11: Unchanged skipping 2025/02/13 21:42:55 DEBUG : both18: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/02/13 21:42:55 DEBUG : both12: Unchanged skipping 2025/02/13 21:42:55 DEBUG : both19: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/02/13 21:42:55 DEBUG : both16: Unchanged skipping 2025/02/13 21:42:55 DEBUG : both2: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/02/13 21:42:55 DEBUG : both2: Unchanged skipping 2025/02/13 21:42:55 DEBUG : both3: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/02/13 21:42:55 DEBUG : both3: Unchanged skipping 2025/02/13 21:42:55 DEBUG : both4: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/02/13 21:42:55 DEBUG : both17: Unchanged skipping 2025/02/13 21:42:55 DEBUG : both5: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/02/13 21:42:55 DEBUG : both5: Unchanged skipping 2025/02/13 21:42:55 DEBUG : both6: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/02/13 21:42:55 DEBUG : both18: Unchanged skipping 2025/02/13 21:42:55 DEBUG : both7: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/02/13 21:42:55 DEBUG : both19: Unchanged skipping 2025/02/13 21:42:55 DEBUG : both8: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/02/13 21:42:55 DEBUG : both4: Unchanged skipping 2025/02/13 21:42:55 DEBUG : both9: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/02/13 21:42:55 DEBUG : both8: Unchanged skipping 2025/02/13 21:42:55 DEBUG : both9: Unchanged skipping 2025/02/13 21:42:55 DEBUG : both7: Unchanged skipping 2025/02/13 21:42:55 DEBUG : both6: Unchanged skipping 2025/02/13 21:42:55 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zegicih0cola': Waiting for transfers to finish 2025/02/13 21:42:55 DEBUG : Waiting for deletions to finish 2025/02/13 21:42:55 INFO : only0: Deleted 2025/02/13 21:42:55 INFO : only12: Deleted 2025/02/13 21:42:55 INFO : only14: Deleted 2025/02/13 21:42:55 INFO : only11: Deleted 2025/02/13 21:42:56 INFO : only7: Deleted 2025/02/13 21:42:56 INFO : only8: Deleted 2025/02/13 21:42:56 INFO : only17: Deleted 2025/02/13 21:42:56 INFO : only15: Deleted 2025/02/13 21:42:56 INFO : only3: Deleted 2025/02/13 21:42:56 INFO : only13: Deleted 2025/02/13 21:42:56 INFO : only10: Deleted 2025/02/13 21:42:56 INFO : only9: Deleted 2025/02/13 21:42:56 INFO : only16: Deleted 2025/02/13 21:42:57 INFO : only6: Deleted 2025/02/13 21:42:57 INFO : only19: Deleted 2025/02/13 21:42:57 INFO : only2: Deleted 2025/02/13 21:42:57 INFO : only1: Deleted 2025/02/13 21:42:57 INFO : only18: Deleted 2025/02/13 21:42:57 INFO : only5: Deleted 2025/02/13 21:42:57 INFO : only4: Deleted 2025/02/13 21:42:57 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zegicih0cola'", Local "Local file system at /tmp/rclone3758268997", Modify Window "1ms" --- PASS: TestSyncConcurrentDelete (67.90s) === RUN TestSyncConcurrentTruncate run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zegicih0cola'", Local "Local file system at /tmp/rclone3758268997", Modify Window "1ms" 2025/02/13 21:43:09 DEBUG : both0: md5 = f56fd2ad36b854296a67b46e475e05ad OK 2025/02/13 21:43:10 DEBUG : only0: md5 = 6901d9c6aa4077a061b1e50b99073cdb OK 2025/02/13 21:43:11 DEBUG : both1: md5 = 41c8948d13d9ecdcd250756367bb5cb8 OK 2025/02/13 21:43:13 DEBUG : only1: md5 = 8b6d0c14771930d94f43e32188cd261e OK 2025/02/13 21:43:14 DEBUG : both2: md5 = acd54b9f85a5e4f89ed84a1a700832f0 OK 2025/02/13 21:43:16 DEBUG : only2: md5 = f369a20d34a5fc3a4de12c55ba61fe70 OK 2025/02/13 21:43:17 DEBUG : both3: md5 = dfd5719b0ab8eb1a2a8c241cedd65c48 OK 2025/02/13 21:43:18 DEBUG : only3: md5 = 69877e8a610814e6d6a43930fbd07f30 OK 2025/02/13 21:43:20 DEBUG : both4: md5 = 9554f23fadf44e3eb4c9a9b8dd24afd6 OK 2025/02/13 21:43:21 DEBUG : only4: md5 = d0f1f959d0dccb63d68fb49b483ae8dd OK 2025/02/13 21:43:23 DEBUG : both5: md5 = 8b0d75ed292665a56239ba4ada4478a5 OK 2025/02/13 21:43:24 DEBUG : only5: md5 = 0c0b8e26f00ac1a2dd705c18697092e9 OK 2025/02/13 21:43:25 DEBUG : both6: md5 = 9c341c7dd6b72c55f46fa07d1280f3e5 OK 2025/02/13 21:43:27 DEBUG : only6: md5 = c5a6335ebf8c87d35c0a127a8096c256 OK 2025/02/13 21:43:28 DEBUG : both7: md5 = 9cc86acdcc3d5776bfde2f12bd6608ff OK 2025/02/13 21:43:30 DEBUG : only7: md5 = ab0e06c5d748d963ec8d5b0fc694985b OK 2025/02/13 21:43:31 DEBUG : both8: md5 = e9008f37965798314540868947d12d37 OK 2025/02/13 21:43:33 DEBUG : only8: md5 = 7924e1d8e7fe3aaa7304f743475c09fc OK 2025/02/13 21:43:34 DEBUG : both9: md5 = cb33cf8ea8fc071d6cd3ea44cc5310e6 OK 2025/02/13 21:43:35 DEBUG : only9: md5 = e633eb99b14de6d5e9480be15196d896 OK 2025/02/13 21:43:37 DEBUG : both10: md5 = 7ba043966f960b64895e41e6f20285dd OK 2025/02/13 21:43:38 DEBUG : only10: md5 = 6726fe44ad65af648c02ebdcd4e5df97 OK 2025/02/13 21:43:40 DEBUG : both11: md5 = 8314336d572fbf07537a58087b1974ac OK 2025/02/13 21:43:41 DEBUG : only11: md5 = 4597faecc5d4f622252d9aff7ac46af3 OK 2025/02/13 21:43:42 DEBUG : both12: md5 = 4cae589e9ab584166d006aea73896946 OK 2025/02/13 21:43:44 DEBUG : only12: md5 = 520f09cd08490f5fd1da857a52bb7c9c OK 2025/02/13 21:43:45 DEBUG : both13: md5 = 9525eb8d59f902f2da24f143b6739588 OK 2025/02/13 21:43:47 DEBUG : only13: md5 = 9d5db8427c027eb7a1317ceb87453d63 OK 2025/02/13 21:43:48 DEBUG : both14: md5 = 06488751cde7362c4861c21a978d68f6 OK 2025/02/13 21:43:50 DEBUG : only14: md5 = 085b4b9462428081bf0cc322b194b2cd OK 2025/02/13 21:43:51 DEBUG : both15: md5 = 456f8fd31e0c46cc3108a1d31cea3ffd OK 2025/02/13 21:43:52 DEBUG : only15: md5 = 2454ff621c9dd7f9c46eefe502a8c7fe OK 2025/02/13 21:43:54 DEBUG : both16: md5 = 36ab8e3d9f540c1e8caf7684b5e85a3f OK 2025/02/13 21:43:55 DEBUG : only16: md5 = 0548b9c95742ea1360483d2afcda44fb OK 2025/02/13 21:43:56 DEBUG : both17: md5 = 59466a67f37dcec841ec27e51be966b2 OK 2025/02/13 21:43:58 DEBUG : only17: md5 = 151048158281f6706a1615436f678563 OK 2025/02/13 21:43:59 DEBUG : both18: md5 = 23065dead0e57f38f18f29625c6ff51d OK 2025/02/13 21:44:00 DEBUG : only18: md5 = e4151fccc502dda95cfb693effca3451 OK 2025/02/13 21:44:02 DEBUG : both19: md5 = 036160939ade6eab733d03b5b8f76937 OK 2025/02/13 21:44:03 DEBUG : only19: md5 = 7243ad2f93d044e9bb28b98236b2e73d OK 2025/02/13 21:44:04 DEBUG : both0: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/02/13 21:44:04 DEBUG : both1: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/02/13 21:44:04 DEBUG : both11: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/02/13 21:44:04 DEBUG : both10: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/02/13 21:44:04 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zegicih0cola': Waiting for checks to finish 2025/02/13 21:44:04 DEBUG : both0: Unchanged skipping 2025/02/13 21:44:04 DEBUG : both12: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/02/13 21:44:04 DEBUG : both12: Unchanged skipping 2025/02/13 21:44:04 DEBUG : both13: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/02/13 21:44:04 DEBUG : both1: Unchanged skipping 2025/02/13 21:44:04 DEBUG : both14: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/02/13 21:44:04 DEBUG : both14: Unchanged skipping 2025/02/13 21:44:04 DEBUG : both15: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/02/13 21:44:04 DEBUG : both11: Unchanged skipping 2025/02/13 21:44:04 DEBUG : both16: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/02/13 21:44:04 DEBUG : both10: Unchanged skipping 2025/02/13 21:44:04 DEBUG : both17: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/02/13 21:44:04 DEBUG : both13: Unchanged skipping 2025/02/13 21:44:04 DEBUG : both18: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/02/13 21:44:04 DEBUG : both15: Unchanged skipping 2025/02/13 21:44:04 DEBUG : both19: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/02/13 21:44:04 DEBUG : both16: Unchanged skipping 2025/02/13 21:44:04 DEBUG : both2: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/02/13 21:44:04 DEBUG : both2: Unchanged skipping 2025/02/13 21:44:04 DEBUG : both3: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/02/13 21:44:04 DEBUG : both17: Unchanged skipping 2025/02/13 21:44:04 DEBUG : both4: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/02/13 21:44:04 DEBUG : both4: Unchanged skipping 2025/02/13 21:44:04 DEBUG : both5: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/02/13 21:44:04 DEBUG : both5: Unchanged skipping 2025/02/13 21:44:04 DEBUG : both6: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/02/13 21:44:04 DEBUG : both6: Unchanged skipping 2025/02/13 21:44:04 DEBUG : both7: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/02/13 21:44:04 DEBUG : both7: Unchanged skipping 2025/02/13 21:44:04 DEBUG : both8: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/02/13 21:44:04 DEBUG : both8: Unchanged skipping 2025/02/13 21:44:04 DEBUG : both9: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/02/13 21:44:04 DEBUG : both9: Unchanged skipping 2025/02/13 21:44:04 DEBUG : only0: Sizes differ (src 0 vs dst 6) 2025/02/13 21:44:04 DEBUG : only1: Sizes differ (src 0 vs dst 6) 2025/02/13 21:44:04 DEBUG : only10: Sizes differ (src 0 vs dst 6) 2025/02/13 21:44:04 DEBUG : only11: Sizes differ (src 0 vs dst 6) 2025/02/13 21:44:04 DEBUG : only12: Sizes differ (src 0 vs dst 6) 2025/02/13 21:44:04 DEBUG : only13: Sizes differ (src 0 vs dst 6) 2025/02/13 21:44:04 DEBUG : only14: Sizes differ (src 0 vs dst 6) 2025/02/13 21:44:04 DEBUG : only15: Sizes differ (src 0 vs dst 6) 2025/02/13 21:44:04 DEBUG : only16: Sizes differ (src 0 vs dst 6) 2025/02/13 21:44:04 DEBUG : only17: Sizes differ (src 0 vs dst 6) 2025/02/13 21:44:04 DEBUG : only18: Sizes differ (src 0 vs dst 6) 2025/02/13 21:44:04 DEBUG : only19: Sizes differ (src 0 vs dst 6) 2025/02/13 21:44:04 DEBUG : only2: Sizes differ (src 0 vs dst 6) 2025/02/13 21:44:04 DEBUG : only3: Sizes differ (src 0 vs dst 6) 2025/02/13 21:44:04 DEBUG : only4: Sizes differ (src 0 vs dst 6) 2025/02/13 21:44:04 DEBUG : only5: Sizes differ (src 0 vs dst 6) 2025/02/13 21:44:04 DEBUG : only6: Sizes differ (src 0 vs dst 6) 2025/02/13 21:44:04 DEBUG : only7: Sizes differ (src 0 vs dst 6) 2025/02/13 21:44:04 DEBUG : only8: Sizes differ (src 0 vs dst 6) 2025/02/13 21:44:04 DEBUG : only9: Sizes differ (src 0 vs dst 6) 2025/02/13 21:44:04 DEBUG : both19: Unchanged skipping 2025/02/13 21:44:04 DEBUG : both3: Unchanged skipping 2025/02/13 21:44:04 DEBUG : both18: Unchanged skipping 2025/02/13 21:44:04 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zegicih0cola': Waiting for transfers to finish 2025/02/13 21:44:05 DEBUG : only11: md5 = 7b8bfd4beb174c7e37cdd2b956bd247b OK 2025/02/13 21:44:05 INFO : only11: Copied (replaced existing) 2025/02/13 21:44:05 DEBUG : only10: md5 = 918ed3571ac807254e4291b7a46fba97 OK 2025/02/13 21:44:05 INFO : only10: Copied (replaced existing) 2025/02/13 21:44:05 DEBUG : only0: md5 = 81d773629f5c4b3e6299ea0e22881e11 OK 2025/02/13 21:44:05 INFO : only0: Copied (replaced existing) 2025/02/13 21:44:05 DEBUG : only1: md5 = 3430f1aa01f46822e8a3468a96f5d789 OK 2025/02/13 21:44:05 INFO : only1: Copied (replaced existing) 2025/02/13 21:44:06 DEBUG : only13: md5 = 61540a4f73440453b810139847ad0c95 OK 2025/02/13 21:44:06 INFO : only13: Copied (replaced existing) 2025/02/13 21:44:06 DEBUG : only12: md5 = 0b41fe52b527b747d1820904f1b5b288 OK 2025/02/13 21:44:06 INFO : only12: Copied (replaced existing) 2025/02/13 21:44:06 DEBUG : only14: md5 = dd2b274b96f127382b10c531895f9206 OK 2025/02/13 21:44:06 INFO : only14: Copied (replaced existing) 2025/02/13 21:44:06 DEBUG : only15: md5 = fcf316eec5919b28551302970de54aa8 OK 2025/02/13 21:44:06 INFO : only15: Copied (replaced existing) 2025/02/13 21:44:07 DEBUG : only16: md5 = 8dfae57226aef455483829e6908c5454 OK 2025/02/13 21:44:07 INFO : only16: Copied (replaced existing) 2025/02/13 21:44:07 DEBUG : only17: md5 = 227768ca93d034eb0bde885ef431b237 OK 2025/02/13 21:44:07 INFO : only17: Copied (replaced existing) 2025/02/13 21:44:07 DEBUG : only19: md5 = 09a4c61b6f368a16c6f7c6df0bfdf3bf OK 2025/02/13 21:44:07 INFO : only19: Copied (replaced existing) 2025/02/13 21:44:07 DEBUG : only18: md5 = 01b868bf6a3ea78c7436ad2f695bf48e OK 2025/02/13 21:44:07 INFO : only18: Copied (replaced existing) 2025/02/13 21:44:08 DEBUG : only2: md5 = 8442c470a345da7bc9fcfdaa083ba73d OK 2025/02/13 21:44:08 INFO : only2: Copied (replaced existing) 2025/02/13 21:44:08 DEBUG : only4: md5 = 6628ac11233e6d821016f0ac2118f4b4 OK 2025/02/13 21:44:08 INFO : only4: Copied (replaced existing) 2025/02/13 21:44:08 DEBUG : only5: md5 = 63d0d8ccc9dbd0ab8c825f6c7b6a108f OK 2025/02/13 21:44:08 INFO : only5: Copied (replaced existing) 2025/02/13 21:44:08 DEBUG : only3: md5 = 22d1bed27122bb0f9d578d946bbecca8 OK 2025/02/13 21:44:08 INFO : only3: Copied (replaced existing) 2025/02/13 21:44:09 DEBUG : only8: md5 = a562aaf64e736e9d93c63dfd80e196ef OK 2025/02/13 21:44:09 INFO : only8: Copied (replaced existing) 2025/02/13 21:44:09 DEBUG : only6: md5 = f906cd93ce8e519e1ba23aba7d3f3979 OK 2025/02/13 21:44:09 INFO : only6: Copied (replaced existing) 2025/02/13 21:44:09 DEBUG : only7: md5 = 8c0dd76c4f1a672ff514bde29e532cc1 OK 2025/02/13 21:44:09 INFO : only7: Copied (replaced existing) 2025/02/13 21:44:09 DEBUG : only9: md5 = 50006712c785927f55039c4e3b73e219 OK 2025/02/13 21:44:09 INFO : only9: Copied (replaced existing) 2025/02/13 21:44:09 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zegicih0cola'", Local "Local file system at /tmp/rclone3758268997", Modify Window "1ms" --- PASS: TestSyncConcurrentTruncate (81.16s) === RUN TestNothingToTransferWithEmptyDirs run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zegicih0cola'", Local "Local file system at /tmp/rclone3758268997", Modify Window "1ms" 2025/02/13 21:44:28 INFO : sub dir: Set directory modification time (using DirSetModTime) 2025/02/13 21:44:28 DEBUG : sub dir: Making directory with metadata 2025/02/13 21:44:29 INFO : sub dir: Made directory with metadata (mtime=2011-12-30T12:59:59Z) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zegicih0cola'", Local "Local file system at /tmp/rclone3758268997", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zegicih0cola'", Local "Local file system at /tmp/rclone3758268997", Modify Window "1ms" 2025/02/13 21:44:46 INFO : sub dir2: Set directory modification time (using DirSetModTime) 2025/02/13 21:44:47 INFO : sub dir2: Set directory modification time (using DirSetModTime) 2025/02/13 21:44:47 INFO : sub dirEmpty/sub dirEmpty2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2025/02/13 21:44:47 INFO : sub dirEmpty: Set directory modification time (using DirSetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zegicih0cola'", Local "Local file system at /tmp/rclone3758268997", Modify Window "1ms" 2025/02/13 21:44:59 DEBUG : gcsdkq814sbtppue42dpsbg8ug: Rmdir: contains trashed file: "sjuo65gk5q3r1199jselk9k9o0" 2025/02/13 21:44:59 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/37qp6d1gohacv723ij3brofbu8/i24n0ln37pa2hv8pctddeuh73o: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" 2025/02/13 21:45:00 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/37qp6d1gohacv723ij3brofbu8: Rmdir: contains trashed file: "i24n0ln37pa2hv8pctddeuh73o" 2025/02/13 21:45:01 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "37qp6d1gohacv723ij3brofbu8" 2025/02/13 21:45:01 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak" 2025/02/13 21:45:02 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak" 2025/02/13 21:45:03 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak" 2025/02/13 21:45:03 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak" 2025/02/13 21:45:04 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/4r13oncfa2rsrr82oqhsqv24ns: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" 2025/02/13 21:45:05 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc: Rmdir: contains trashed file: "4r13oncfa2rsrr82oqhsqv24ns" 2025/02/13 21:45:05 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak" 2025/02/13 21:45:06 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestNothingToTransferWithEmptyDirs (39.05s) === RUN TestNothingToTransferWithoutEmptyDirs run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zegicih0cola'", Local "Local file system at /tmp/rclone3758268997", Modify Window "1ms" 2025/02/13 21:45:08 INFO : sub dir: Set directory modification time (using DirSetModTime) 2025/02/13 21:45:08 DEBUG : sub dir: Making directory with metadata 2025/02/13 21:45:08 INFO : sub dir: Made directory with metadata (mtime=2011-12-30T12:59:59Z) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zegicih0cola'", Local "Local file system at /tmp/rclone3758268997", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zegicih0cola'", Local "Local file system at /tmp/rclone3758268997", Modify Window "1ms" 2025/02/13 21:45:30 INFO : sub dir2: Set directory modification time (using DirSetModTime) 2025/02/13 21:45:31 INFO : sub dir2: Set directory modification time (using DirSetModTime) 2025/02/13 21:45:31 INFO : sub dirEmpty/sub dirEmpty2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2025/02/13 21:45:31 INFO : sub dirEmpty: Set directory modification time (using DirSetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zegicih0cola'", Local "Local file system at /tmp/rclone3758268997", Modify Window "1ms" 2025/02/13 21:45:43 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/37qp6d1gohacv723ij3brofbu8/i24n0ln37pa2hv8pctddeuh73o: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" 2025/02/13 21:45:43 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/37qp6d1gohacv723ij3brofbu8: Rmdir: contains trashed file: "i24n0ln37pa2hv8pctddeuh73o" 2025/02/13 21:45:44 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "37qp6d1gohacv723ij3brofbu8" 2025/02/13 21:45:45 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak" 2025/02/13 21:45:46 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak" 2025/02/13 21:45:47 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak" 2025/02/13 21:45:47 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak" 2025/02/13 21:45:48 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/4r13oncfa2rsrr82oqhsqv24ns: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" 2025/02/13 21:45:49 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc: Rmdir: contains trashed file: "4r13oncfa2rsrr82oqhsqv24ns" 2025/02/13 21:45:49 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak" 2025/02/13 21:45:49 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestNothingToTransferWithoutEmptyDirs (43.78s) PASS 2025/02/13 21:45:51 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zegicih0cola': Purge remote "./sync.test -test.v -test.timeout 1h0m0s -remote TestCryptDrive: -verbose" - Finished OK in 15m13.428635689s (try 1/5)