"./sync.test -test.v -test.timeout 1h0m0s -remote TestCryptDrive: -verbose -fast-list" - Starting (try 1/5) 2025/05/14 03:19:27 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-zevijan8roce" 2025/05/14 03:19:27 DEBUG : Using config file from "/home/rclone/.rclone.conf" 2025/05/14 03:19:27 DEBUG : Creating backend with remote "TestDrive:crypt/ufl16g1kejeblfpcdf7548e43i8hq909bkinusgb0bt9llb2ig7g" 2025/05/14 03:19:27 DEBUG : TestDrive: Loaded invalid token from config file - ignoring 2025/05/14 03:19:27 DEBUG : Saving config "token" in section "TestDrive" of the config file 2025/05/14 03:19:27 DEBUG : TestDrive: Saved new token in config file 2025/05/14 03:19:28 DEBUG : Creating backend with remote "/tmp/rclone2511166019" === RUN TestPipe --- PASS: TestPipe (0.00s) === RUN TestPipeConcurrent --- PASS: TestPipeConcurrent (0.04s) === 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-zevijan8roce'", Local "Local file system at /tmp/rclone2511166019", Modify Window "1ms" 2025/05/14 03:19:30 DEBUG : Added delayed dir = "sub dir", newDst= 2025/05/14 03:19:30 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2025/05/14 03:19:30 NOTICE: sub dir/hello world: Skipped copy as --dry-run is set (size 11) 2025/05/14 03:19:30 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zevijan8roce': Waiting for checks to finish 2025/05/14 03:19:30 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zevijan8roce': Waiting for transfers to finish 2025/05/14 03:19:30 NOTICE: sub dir: Skipped set directory modification time as --dry-run is set run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zevijan8roce'", Local "Local file system at /tmp/rclone2511166019", Modify Window "1ms" --- PASS: TestCopyWithDryRun (2.30s) === RUN TestCopy run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zevijan8roce'", Local "Local file system at /tmp/rclone2511166019", Modify Window "1ms" 2025/05/14 03:19:31 INFO : sub dir: Set directory modification time (using DirSetModTime) 2025/05/14 03:19:31 DEBUG : Added delayed dir = "sub dir", newDst= 2025/05/14 03:19:31 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2025/05/14 03:19:31 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zevijan8roce': Waiting for checks to finish 2025/05/14 03:19:31 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zevijan8roce': Waiting for transfers to finish 2025/05/14 03:19:33 DEBUG : sub dir/hello world: md5 = e9b15e9268696d599175743a5869fc4b OK 2025/05/14 03:19:33 INFO : sub dir/hello world: Copied (new) 2025/05/14 03:19:34 INFO : sub dir: Set directory modification time (using DirSetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zevijan8roce'", Local "Local file system at /tmp/rclone2511166019", Modify Window "1ms" 2025/05/14 03:19:36 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestCopy (6.29s) === RUN TestCopyMetadata run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zevijan8roce'", Local "Local file system at /tmp/rclone2511166019", Modify Window "1ms" 2025/05/14 03:19:37 DEBUG : metadata sub dir: Making directory with metadata 2025/05/14 03:19:37 INFO : metadata sub dir: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2025/05/14 03:19:37 DEBUG : empty metadata sub dir: Making directory with metadata 2025/05/14 03:19:37 INFO : empty metadata sub dir: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2025/05/14 03:19:37 DEBUG : Local file system at /tmp/rclone2511166019: File to upload is small (21 bytes), uploading instead of streaming 2025/05/14 03:19:37 DEBUG : metadata sub dir/hello metadata world: md5 = baa7a013449dbba2b1ed02b5cfb4e1a2 OK 2025/05/14 03:19:37 DEBUG : metadata sub dir/hello metadata world: Size and md5 of src and dst objects identical 2025/05/14 03:19:37 INFO : metadata sub dir: Set directory modification time (using DirSetModTime) 2025/05/14 03:19:38 DEBUG : Google drive root 'crypt/ufl16g1kejeblfpcdf7548e43i8hq909bkinusgb0bt9llb2ig7g': Skipping btime metadata as can't update it on an existing file: 2025-05-14T03:19:37.563804203Z 2025/05/14 03:19:38 INFO : empty metadata sub dir: Updated directory metadata 2025/05/14 03:19:38 DEBUG : Google drive root 'crypt/ufl16g1kejeblfpcdf7548e43i8hq909bkinusgb0bt9llb2ig7g': Skipping btime metadata as can't update it on an existing file: 2025-05-14T03:19:37.563804203Z 2025/05/14 03:19:39 INFO : metadata sub dir: Updated directory metadata 2025/05/14 03:19:39 DEBUG : metadata sub dir/hello metadata world: Need to transfer - File not found at Destination 2025/05/14 03:19:39 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zevijan8roce': Waiting for checks to finish 2025/05/14 03:19:39 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zevijan8roce': Waiting for transfers to finish 2025/05/14 03:19:40 DEBUG : metadata sub dir/hello metadata world: md5 = 4b18e1f863ea7556e30c03514b6847be OK 2025/05/14 03:19:40 INFO : metadata sub dir/hello metadata world: Copied (new) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zevijan8roce'", Local "Local file system at /tmp/rclone2511166019", Modify Window "1ms" 2025/05/14 03:19:43 DEBUG : fg45q1rm3kh00nmmkk4m6ihmrcnel1p7551kqhjr9bk2gtd2gbf0: Rmdir: contains trashed file: "dmuvulfij81f693ur0f1vvbvq9v6iscp56daas3m51n9li5e3470" --- PASS: TestCopyMetadata (7.94s) === RUN TestCopyMetadataNoEmptyDirs run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zevijan8roce'", Local "Local file system at /tmp/rclone2511166019", Modify Window "1ms" 2025/05/14 03:19:45 DEBUG : metadata sub dir: Making directory with metadata 2025/05/14 03:19:45 INFO : metadata sub dir: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2025/05/14 03:19:45 DEBUG : empty metadata sub dir: Making directory with metadata 2025/05/14 03:19:45 INFO : empty metadata sub dir: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2025/05/14 03:19:45 DEBUG : Local file system at /tmp/rclone2511166019: File to upload is small (21 bytes), uploading instead of streaming 2025/05/14 03:19:45 DEBUG : metadata sub dir/hello metadata world: md5 = baa7a013449dbba2b1ed02b5cfb4e1a2 OK 2025/05/14 03:19:45 DEBUG : metadata sub dir/hello metadata world: Size and md5 of src and dst objects identical 2025/05/14 03:19:45 INFO : metadata sub dir: Set directory modification time (using DirSetModTime) 2025/05/14 03:19:45 DEBUG : Added delayed dir = "empty metadata sub dir", newDst= 2025/05/14 03:19:45 DEBUG : Added delayed dir = "metadata sub dir", newDst= 2025/05/14 03:19:45 DEBUG : metadata sub dir/hello metadata world: Need to transfer - File not found at Destination 2025/05/14 03:19:45 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zevijan8roce': Waiting for checks to finish 2025/05/14 03:19:45 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zevijan8roce': Waiting for transfers to finish 2025/05/14 03:19:47 DEBUG : metadata sub dir/hello metadata world: md5 = 2febb2f16f80effa4ac8c69c922999e0 OK 2025/05/14 03:19:47 INFO : metadata sub dir/hello metadata world: Copied (new) 2025/05/14 03:19:47 DEBUG : Google drive root 'crypt/ufl16g1kejeblfpcdf7548e43i8hq909bkinusgb0bt9llb2ig7g': Skipping btime metadata as can't update it on an existing file: 2025-05-14T03:19:45.50781754Z 2025/05/14 03:19:48 INFO : metadata sub dir: Updated directory metadata run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zevijan8roce'", Local "Local file system at /tmp/rclone2511166019", Modify Window "1ms" 2025/05/14 03:19:51 DEBUG : fg45q1rm3kh00nmmkk4m6ihmrcnel1p7551kqhjr9bk2gtd2gbf0: Rmdir: contains trashed file: "dmuvulfij81f693ur0f1vvbvq9v6iscp56daas3m51n9li5e3470" --- PASS: TestCopyMetadataNoEmptyDirs (7.02s) === RUN TestCopyMissingDirectory run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zevijan8roce'", Local "Local file system at /tmp/rclone2511166019", Modify Window "1ms" 2025/05/14 03:19:52 DEBUG : Creating backend with remote "/non-existing" 2025/05/14 03:19:52 ERROR : Local file system at /non-existing: error reading source root directory: directory not found 2025/05/14 03:19:52 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zevijan8roce': Waiting for checks to finish 2025/05/14 03:19:52 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zevijan8roce': Waiting for transfers to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zevijan8roce'", Local "Local file system at /tmp/rclone2511166019", Modify Window "1ms" --- PASS: TestCopyMissingDirectory (1.22s) === RUN TestCopyNoTraverse run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zevijan8roce'", Local "Local file system at /tmp/rclone2511166019", Modify Window "1ms" 2025/05/14 03:19:53 DEBUG : Added delayed dir = "sub dir", newDst= 2025/05/14 03:19:53 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2025/05/14 03:19:53 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zevijan8roce': Waiting for checks to finish 2025/05/14 03:19:53 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zevijan8roce': Waiting for transfers to finish 2025/05/14 03:19:56 DEBUG : sub dir/hello world: md5 = c361c7f361ad42135709f1ac3102a9f3 OK 2025/05/14 03:19:56 INFO : sub dir/hello world: Copied (new) 2025/05/14 03:19:56 INFO : sub dir: Set directory modification time (using DirSetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zevijan8roce'", Local "Local file system at /tmp/rclone2511166019", Modify Window "1ms" 2025/05/14 03:19:58 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestCopyNoTraverse (5.90s) === RUN TestCopyCheckFirst run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zevijan8roce'", Local "Local file system at /tmp/rclone2511166019", Modify Window "1ms" 2025/05/14 03:19:59 INFO : Encrypted drive 'TestCryptDrive:rclone-test-zevijan8roce': Running all checks before starting transfers 2025/05/14 03:19:59 DEBUG : Added delayed dir = "sub dir", newDst= 2025/05/14 03:19:59 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2025/05/14 03:19:59 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zevijan8roce': Waiting for checks to finish 2025/05/14 03:19:59 INFO : Encrypted drive 'TestCryptDrive:rclone-test-zevijan8roce': Checks finished, now starting transfers 2025/05/14 03:19:59 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zevijan8roce': Waiting for transfers to finish 2025/05/14 03:20:02 DEBUG : sub dir/hello world: md5 = 0c734c3b3403d567cd1baba7b70b0647 OK 2025/05/14 03:20:02 INFO : sub dir/hello world: Copied (new) 2025/05/14 03:20:02 INFO : sub dir: Set directory modification time (using DirSetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zevijan8roce'", Local "Local file system at /tmp/rclone2511166019", Modify Window "1ms" 2025/05/14 03:20:04 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestCopyCheckFirst (6.05s) === RUN TestSyncNoTraverse run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zevijan8roce'", Local "Local file system at /tmp/rclone2511166019", Modify Window "1ms" 2025/05/14 03:20:05 ERROR : Ignoring --no-traverse with sync 2025/05/14 03:20:05 DEBUG : Added delayed dir = "sub dir", newDst= 2025/05/14 03:20:05 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2025/05/14 03:20:05 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zevijan8roce': Waiting for checks to finish 2025/05/14 03:20:05 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zevijan8roce': Waiting for transfers to finish 2025/05/14 03:20:08 DEBUG : sub dir/hello world: md5 = e0cfef2e47667b9f9f07a7b454c2b726 OK 2025/05/14 03:20:08 INFO : sub dir/hello world: Copied (new) 2025/05/14 03:20:08 DEBUG : Waiting for deletions to finish 2025/05/14 03:20:08 INFO : sub dir: Set directory modification time (using DirSetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zevijan8roce'", Local "Local file system at /tmp/rclone2511166019", Modify Window "1ms" 2025/05/14 03:20:10 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestSyncNoTraverse (5.92s) === RUN TestCopyWithDepth run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zevijan8roce'", Local "Local file system at /tmp/rclone2511166019", Modify Window "1ms" 2025/05/14 03:20:11 DEBUG : hello world2: Need to transfer - File not found at Destination 2025/05/14 03:20:11 DEBUG : Added delayed dir = "sub dir", newDst= 2025/05/14 03:20:11 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zevijan8roce': Waiting for checks to finish 2025/05/14 03:20:11 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zevijan8roce': Waiting for transfers to finish 2025/05/14 03:20:13 DEBUG : hello world2: md5 = 3c66b9f4a40fa6831b0eb1452e3245f1 OK 2025/05/14 03:20:13 INFO : hello world2: Copied (new) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zevijan8roce'", Local "Local file system at /tmp/rclone2511166019", Modify Window "1ms" --- PASS: TestCopyWithDepth (3.12s) === RUN TestCopyWithFilesFrom run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zevijan8roce'", Local "Local file system at /tmp/rclone2511166019", Modify Window "1ms" 2025/05/14 03:20:14 DEBUG : potato2: Need to transfer - File not found at Destination 2025/05/14 03:20:14 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zevijan8roce': Waiting for checks to finish 2025/05/14 03:20:14 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zevijan8roce': Waiting for transfers to finish 2025/05/14 03:20:16 DEBUG : potato2: md5 = a02a70349ee3b9a153d403dd5b29fecb OK 2025/05/14 03:20:16 INFO : potato2: Copied (new) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zevijan8roce'", Local "Local file system at /tmp/rclone2511166019", Modify Window "1ms" --- PASS: TestCopyWithFilesFrom (3.26s) === RUN TestCopyWithFilesFromAndNoTraverse run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zevijan8roce'", Local "Local file system at /tmp/rclone2511166019", Modify Window "1ms" 2025/05/14 03:20:18 DEBUG : potato2: Need to transfer - File not found at Destination 2025/05/14 03:20:18 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zevijan8roce': Waiting for checks to finish 2025/05/14 03:20:18 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zevijan8roce': Waiting for transfers to finish 2025/05/14 03:20:19 DEBUG : potato2: md5 = cce7eed6f39fb3579a47cf4e3c7c1af6 OK 2025/05/14 03:20:19 INFO : potato2: Copied (new) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zevijan8roce'", Local "Local file system at /tmp/rclone2511166019", Modify Window "1ms" --- PASS: TestCopyWithFilesFromAndNoTraverse (3.34s) === RUN TestCopyEmptyDirectories run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zevijan8roce'", Local "Local file system at /tmp/rclone2511166019", Modify Window "1ms" 2025/05/14 03:20:21 DEBUG : sub dir2/sub sub dir2: Making directory with metadata 2025/05/14 03:20:21 INFO : sub dir2/sub sub dir2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2025/05/14 03:20:21 INFO : sub dir2: Set directory modification time (using DirSetModTime) 2025/05/14 03:20:21 INFO : sub dir: Set directory modification time (using DirSetModTime) 2025/05/14 03:20:21 DEBUG : sub dir: Making directory with metadata 2025/05/14 03:20:22 INFO : sub dir: Made directory with metadata (mtime=2001-02-03T04:05:06.499999999Z) 2025/05/14 03:20:22 DEBUG : sub dir2: Making directory with metadata 2025/05/14 03:20:23 INFO : sub dir2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2025/05/14 03:20:23 DEBUG : sub dir2/sub sub dir2: Making directory with metadata 2025/05/14 03:20:23 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2025/05/14 03:20:24 INFO : sub dir2/sub sub dir2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2025/05/14 03:20:24 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zevijan8roce': Waiting for checks to finish 2025/05/14 03:20:24 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zevijan8roce': Waiting for transfers to finish 2025/05/14 03:20:24 DEBUG : sub dir/hello world: md5 = 7d073c431e0b21c3a83a7075a1aa5f8f OK 2025/05/14 03:20:24 INFO : sub dir/hello world: Copied (new) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zevijan8roce'", Local "Local file system at /tmp/rclone2511166019", Modify Window "1ms" 2025/05/14 03:20:28 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc: Rmdir: contains trashed file: "cv6a9uf28ngrajena8kt5ijjn0" 2025/05/14 03:20:29 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestCopyEmptyDirectories (8.91s) === RUN TestCopyNoEmptyDirectories run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zevijan8roce'", Local "Local file system at /tmp/rclone2511166019", Modify Window "1ms" 2025/05/14 03:20:30 INFO : sub dir2: Making directory 2025/05/14 03:20:30 DEBUG : sub dir2/sub sub dir2: Making directory with metadata 2025/05/14 03:20:30 INFO : sub dir2/sub sub dir2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2025/05/14 03:20:30 DEBUG : Added delayed dir = "sub dir", newDst= 2025/05/14 03:20:30 DEBUG : Added delayed dir = "sub dir2", newDst= 2025/05/14 03:20:30 DEBUG : Added delayed dir = "sub dir2/sub sub dir2", newDst= 2025/05/14 03:20:30 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2025/05/14 03:20:30 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zevijan8roce': Waiting for checks to finish 2025/05/14 03:20:30 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zevijan8roce': Waiting for transfers to finish 2025/05/14 03:20:32 DEBUG : sub dir/hello world: md5 = 47dff8a25df24aaed11c1633f8c9960f OK 2025/05/14 03:20:32 INFO : sub dir/hello world: Copied (new) 2025/05/14 03:20:33 INFO : sub dir: Set directory modification time (using DirSetModTime) 2025/05/14 03:20:35 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestCopyNoEmptyDirectories (5.48s) === RUN TestMoveEmptyDirectories run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zevijan8roce'", Local "Local file system at /tmp/rclone2511166019", Modify Window "1ms" 2025/05/14 03:20:35 DEBUG : sub dir2: Making directory with metadata 2025/05/14 03:20:35 INFO : sub dir2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2025/05/14 03:20:35 DEBUG : sub dir: Making directory with metadata 2025/05/14 03:20:36 INFO : sub dir: Made directory with metadata (mtime=2025-05-14T03:20:35.731901728Z) 2025/05/14 03:20:36 DEBUG : sub dir2: Making directory with metadata 2025/05/14 03:20:37 INFO : sub dir2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2025/05/14 03:20:37 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2025/05/14 03:20:37 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zevijan8roce': Waiting for checks to finish 2025/05/14 03:20:37 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zevijan8roce': Waiting for transfers to finish 2025/05/14 03:20:38 DEBUG : sub dir/hello world: md5 = 1b2649665b6aa25acb8efd239c022d9e OK 2025/05/14 03:20:38 INFO : sub dir/hello world: Copied (new) 2025/05/14 03:20:38 INFO : sub dir/hello world: Deleted run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zevijan8roce'", Local "Local file system at /tmp/rclone2511166019", Modify Window "1ms" 2025/05/14 03:20:41 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestMoveEmptyDirectories (7.08s) === RUN TestSyncNoUpdateDirModtime run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zevijan8roce'", Local "Local file system at /tmp/rclone2511166019", Modify Window "1ms" 2025/05/14 03:20:42 DEBUG : sub dir no update dir modtime: Making directory with metadata 2025/05/14 03:20:42 INFO : sub dir no update dir modtime: Made directory with metadata (mtime=2001-02-03T04:05:06.499999999Z) 2025/05/14 03:20:44 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zevijan8roce': Waiting for checks to finish 2025/05/14 03:20:44 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zevijan8roce': Waiting for transfers to finish 2025/05/14 03:20:44 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zevijan8roce'", Local "Local file system at /tmp/rclone2511166019", Modify Window "1ms" --- PASS: TestSyncNoUpdateDirModtime (4.02s) === RUN TestMoveNoEmptyDirectories run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zevijan8roce'", Local "Local file system at /tmp/rclone2511166019", Modify Window "1ms" 2025/05/14 03:20:46 INFO : sub dir2: Making directory 2025/05/14 03:20:47 DEBUG : Added delayed dir = "sub dir", newDst= 2025/05/14 03:20:47 DEBUG : Added delayed dir = "sub dir2", newDst= 2025/05/14 03:20:47 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2025/05/14 03:20:47 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zevijan8roce': Waiting for checks to finish 2025/05/14 03:20:47 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zevijan8roce': Waiting for transfers to finish 2025/05/14 03:20:49 DEBUG : sub dir/hello world: md5 = 32f29b9c76ba06d97cca36fe9e6302ec OK 2025/05/14 03:20:49 INFO : sub dir/hello world: Copied (new) 2025/05/14 03:20:49 INFO : sub dir/hello world: Deleted 2025/05/14 03:20:49 INFO : sub dir: Set directory modification time (using DirSetModTime) 2025/05/14 03:20:51 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestMoveNoEmptyDirectories (5.04s) === RUN TestSyncEmptyDirectories run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zevijan8roce'", Local "Local file system at /tmp/rclone2511166019", Modify Window "1ms" 2025/05/14 03:20:51 DEBUG : sub dir2: Making directory with metadata 2025/05/14 03:20:51 INFO : sub dir2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2025/05/14 03:20:51 INFO : sub dir: Set directory modification time (using DirSetModTime) 2025/05/14 03:20:52 DEBUG : sub dir: Making directory with metadata 2025/05/14 03:20:52 INFO : sub dir: Made directory with metadata (mtime=2001-02-03T04:05:06.499999999Z) 2025/05/14 03:20:52 DEBUG : sub dir2: Making directory with metadata 2025/05/14 03:20:53 INFO : sub dir2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2025/05/14 03:20:53 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2025/05/14 03:20:53 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zevijan8roce': Waiting for checks to finish 2025/05/14 03:20:53 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zevijan8roce': Waiting for transfers to finish 2025/05/14 03:20:55 DEBUG : sub dir/hello world: md5 = 67bfdb3b3bfc80836d7ff1d65d063b07 OK 2025/05/14 03:20:55 INFO : sub dir/hello world: Copied (new) 2025/05/14 03:20:55 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zevijan8roce'", Local "Local file system at /tmp/rclone2511166019", Modify Window "1ms" 2025/05/14 03:20:58 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestSyncEmptyDirectories (7.34s) === RUN TestSyncSetDelayedModTimes run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zevijan8roce'", Local "Local file system at /tmp/rclone2511166019", Modify Window "1ms" sync_test.go:507: Backend doesn't have DirModTimeUpdatesOnWrite set --- SKIP: TestSyncSetDelayedModTimes (0.45s) === RUN TestSyncNoEmptyDirectories run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zevijan8roce'", Local "Local file system at /tmp/rclone2511166019", Modify Window "1ms" 2025/05/14 03:20:59 INFO : sub dir2: Making directory 2025/05/14 03:20:59 DEBUG : Added delayed dir = "sub dir", newDst= 2025/05/14 03:20:59 DEBUG : Added delayed dir = "sub dir2", newDst= 2025/05/14 03:20:59 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2025/05/14 03:20:59 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zevijan8roce': Waiting for checks to finish 2025/05/14 03:20:59 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zevijan8roce': Waiting for transfers to finish 2025/05/14 03:21:01 DEBUG : sub dir/hello world: md5 = b19c772fbd4662d8c1783417045c6e36 OK 2025/05/14 03:21:01 INFO : sub dir/hello world: Copied (new) 2025/05/14 03:21:01 DEBUG : Waiting for deletions to finish 2025/05/14 03:21:02 INFO : sub dir: Set directory modification time (using DirSetModTime) 2025/05/14 03:21:04 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestSyncNoEmptyDirectories (5.46s) === RUN TestServerSideCopy run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zevijan8roce'", Local "Local file system at /tmp/rclone2511166019", Modify Window "1ms" 2025/05/14 03:21:07 DEBUG : sub dir/hello world: md5 = 9ae2d30dea8f201297dadcf9c988786b OK 2025/05/14 03:21:07 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-bexowoz7lice" 2025/05/14 03:21:07 DEBUG : Creating backend with remote "TestDrive:crypt/jki01l0dnc0h2920l0fk9m0a5ojpreikfpio2bsbh3fsfevs33ig" sync_test.go:590: Server side copy (if possible) Encrypted drive 'TestCryptDrive:rclone-test-zevijan8roce' -> Encrypted drive 'TestCryptDrive:rclone-test-bexowoz7lice' 2025/05/14 03:21:09 DEBUG : Added delayed dir = "sub dir", newDst= 2025/05/14 03:21:09 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2025/05/14 03:21:09 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-bexowoz7lice': Waiting for checks to finish 2025/05/14 03:21:09 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-bexowoz7lice': Waiting for transfers to finish 2025/05/14 03:21:12 INFO : sub dir/hello world: Copied (server-side copy) 2025/05/14 03:21:12 INFO : sub dir: Set directory modification time (using DirSetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zevijan8roce'", Local "Local file system at /tmp/rclone2511166019", Modify Window "1ms" 2025/05/14 03:21:13 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-bexowoz7lice': Purge remote 2025/05/14 03:21:15 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestServerSideCopy (11.80s) === RUN TestCopyOverSelf run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zevijan8roce'", Local "Local file system at /tmp/rclone2511166019", Modify Window "1ms" 2025/05/14 03:21:19 DEBUG : sub dir/hello world: md5 = e28e3ec52cfd722fdd3b8206ad11ce4c OK 2025/05/14 03:21:20 INFO : sub dir: Set directory modification time (using SetModTime) 2025/05/14 03:21:20 DEBUG : Added delayed dir = "sub dir", newDst=sub dir 2025/05/14 03:21:20 DEBUG : sub dir/hello world: Sizes differ (src 17 vs dst 11) 2025/05/14 03:21:20 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zevijan8roce': Waiting for checks to finish 2025/05/14 03:21:20 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zevijan8roce': Waiting for transfers to finish 2025/05/14 03:21:21 DEBUG : sub dir/hello world: md5 = 06ee934143ae901d057360ceb42f9e35 OK 2025/05/14 03:21:21 INFO : sub dir/hello world: Copied (replaced existing) 2025/05/14 03:21:22 INFO : sub dir: Set directory modification time (using SetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zevijan8roce'", Local "Local file system at /tmp/rclone2511166019", Modify Window "1ms" 2025/05/14 03:21:24 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestCopyOverSelf (8.29s) === RUN TestServerSideCopyOverSelf run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zevijan8roce'", Local "Local file system at /tmp/rclone2511166019", Modify Window "1ms" 2025/05/14 03:21:27 DEBUG : sub dir/hello world: md5 = 9bff0c7a2e0cb63bee988b868711f2c2 OK 2025/05/14 03:21:27 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-mujazaq5qija" 2025/05/14 03:21:27 DEBUG : Creating backend with remote "TestDrive:crypt/j788djilquedlf07ijquc6q218aq2cl25rml92lg6dcqtqfqh2ag" sync_test.go:626: Server side copy (if possible) Encrypted drive 'TestCryptDrive:rclone-test-zevijan8roce' -> Encrypted drive 'TestCryptDrive:rclone-test-mujazaq5qija' 2025/05/14 03:21:29 DEBUG : Added delayed dir = "sub dir", newDst= 2025/05/14 03:21:29 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2025/05/14 03:21:29 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mujazaq5qija': Waiting for checks to finish 2025/05/14 03:21:29 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mujazaq5qija': Waiting for transfers to finish 2025/05/14 03:21:31 INFO : sub dir/hello world: Copied (server-side copy) 2025/05/14 03:21:32 INFO : sub dir: Set directory modification time (using DirSetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zevijan8roce'", Local "Local file system at /tmp/rclone2511166019", Modify Window "1ms" 2025/05/14 03:21:34 DEBUG : sub dir/hello world: md5 = 0b7cafdb934ffc9619bb69f0dc366914 OK 2025/05/14 03:21:35 DEBUG : sub dir: Directory modification time the same (differ by 0s, within tolerance 1ms) 2025/05/14 03:21:35 DEBUG : Added delayed dir = "sub dir", newDst=sub dir 2025/05/14 03:21:35 DEBUG : sub dir/hello world: Sizes differ (src 17 vs dst 11) 2025/05/14 03:21:35 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mujazaq5qija': Waiting for checks to finish 2025/05/14 03:21:35 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mujazaq5qija': Waiting for transfers to finish 2025/05/14 03:21:36 INFO : sub dir/hello world: Copied (server-side copy) 2025/05/14 03:21:37 INFO : sub dir: Set directory modification time (using SetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zevijan8roce'", Local "Local file system at /tmp/rclone2511166019", Modify Window "1ms" 2025/05/14 03:21:37 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mujazaq5qija': Purge remote 2025/05/14 03:21:39 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestServerSideCopyOverSelf (15.76s) === RUN TestMoveOverSelf run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zevijan8roce'", Local "Local file system at /tmp/rclone2511166019", Modify Window "1ms" 2025/05/14 03:21:43 DEBUG : sub dir/hello world: md5 = 0b063b2d5c33b01f31deb5e7c20b200a OK 2025/05/14 03:21:44 INFO : sub dir: Set directory modification time (using SetModTime) 2025/05/14 03:21:44 DEBUG : Added delayed dir = "sub dir", newDst=sub dir 2025/05/14 03:21:44 DEBUG : sub dir/hello world: Sizes differ (src 17 vs dst 11) 2025/05/14 03:21:44 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zevijan8roce': Waiting for checks to finish 2025/05/14 03:21:44 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zevijan8roce': Waiting for transfers to finish 2025/05/14 03:21:45 DEBUG : sub dir/hello world: md5 = 423737bb52e4a5c93f85f9cfe3ca2dae OK 2025/05/14 03:21:45 INFO : sub dir/hello world: Copied (replaced existing) 2025/05/14 03:21:45 INFO : sub dir/hello world: Deleted 2025/05/14 03:21:46 INFO : sub dir: Set directory modification time (using SetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zevijan8roce'", Local "Local file system at /tmp/rclone2511166019", Modify Window "1ms" 2025/05/14 03:21:47 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestMoveOverSelf (7.88s) === RUN TestServerSideMoveOverSelf run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zevijan8roce'", Local "Local file system at /tmp/rclone2511166019", Modify Window "1ms" 2025/05/14 03:21:51 DEBUG : sub dir/hello world: md5 = 9e23fb4b8e6d44436b4141e14f88b5e5 OK 2025/05/14 03:21:51 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-zunocej2hevu" 2025/05/14 03:21:51 DEBUG : Config file has changed externally - reloading 2025/05/14 03:21:51 DEBUG : Creating backend with remote "TestDrive:crypt/b8l88u6ohc4s0rhha6pua3lhvd3t10obueab71c7ss1vj88d5dlg" sync_test.go:671: Server side copy (if possible) Encrypted drive 'TestCryptDrive:rclone-test-zevijan8roce' -> Encrypted drive 'TestCryptDrive:rclone-test-zunocej2hevu' 2025/05/14 03:21:53 DEBUG : Added delayed dir = "sub dir", newDst= 2025/05/14 03:21:53 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2025/05/14 03:21:53 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zunocej2hevu': Waiting for checks to finish 2025/05/14 03:21:53 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zunocej2hevu': Waiting for transfers to finish 2025/05/14 03:21:55 INFO : sub dir/hello world: Copied (server-side copy) 2025/05/14 03:21:55 INFO : sub dir: Set directory modification time (using DirSetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zevijan8roce'", Local "Local file system at /tmp/rclone2511166019", Modify Window "1ms" 2025/05/14 03:21:58 DEBUG : sub dir/hello world: md5 = e65bec82057cc4b024590cf37cb3b61f OK 2025/05/14 03:21:58 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zunocej2hevu': Using server-side directory move 2025/05/14 03:21:58 INFO : Encrypted drive 'TestCryptDrive:rclone-test-zunocej2hevu': Server side directory move failed - fallback to file moves: can't copy directory - destination already exists 2025/05/14 03:21:59 DEBUG : sub dir: Directory modification time the same (differ by 0s, within tolerance 1ms) 2025/05/14 03:21:59 DEBUG : Added delayed dir = "sub dir", newDst=sub dir 2025/05/14 03:21:59 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zunocej2hevu': Waiting for checks to finish 2025/05/14 03:21:59 DEBUG : sub dir/hello world: Sizes differ (src 17 vs dst 11) 2025/05/14 03:21:59 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zunocej2hevu': Waiting for transfers to finish 2025/05/14 03:21:59 INFO : sub dir/hello world: Deleted 2025/05/14 03:22:00 INFO : sub dir/hello world: Moved (server-side) 2025/05/14 03:22:00 INFO : sub dir: Set directory modification time (using SetModTime) 2025/05/14 03:22:02 DEBUG : sub dir/hello world: md5 = a8fb0a272c31ba0b140e8f162805925a OK 2025/05/14 03:22:03 DEBUG : testing file moves 2025/05/14 03:22:03 DEBUG : sub dir: Directory modification time the same (differ by 0s, within tolerance 1ms) 2025/05/14 03:22:03 DEBUG : Added delayed dir = "sub dir", newDst=sub dir 2025/05/14 03:22:03 DEBUG : sub dir/hello world: Sizes differ (src 24 vs dst 17) 2025/05/14 03:22:03 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zunocej2hevu': Waiting for checks to finish 2025/05/14 03:22:03 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zunocej2hevu': Waiting for transfers to finish 2025/05/14 03:22:04 INFO : sub dir/hello world: Deleted 2025/05/14 03:22:04 INFO : sub dir/hello world: Moved (server-side) 2025/05/14 03:22:05 INFO : sub dir: Set directory modification time (using SetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zevijan8roce'", Local "Local file system at /tmp/rclone2511166019", Modify Window "1ms" 2025/05/14 03:22:06 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zunocej2hevu': Purge remote --- PASS: TestServerSideMoveOverSelf (20.23s) === RUN TestCopyAfterDelete run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zevijan8roce'", Local "Local file system at /tmp/rclone2511166019", Modify Window "1ms" 2025/05/14 03:22:11 DEBUG : sub dir/hello world: md5 = 675d374547a2cd571b8f679e38ed6931 OK 2025/05/14 03:22:11 ERROR : : error listing: directory not found 2025/05/14 03:22:11 INFO : Local file system at /tmp/rclone2511166019: Making directory 2025/05/14 03:22:12 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zevijan8roce': Waiting for checks to finish 2025/05/14 03:22:12 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zevijan8roce': Waiting for transfers to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zevijan8roce'", Local "Local file system at /tmp/rclone2511166019", Modify Window "1ms" 2025/05/14 03:22:13 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestCopyAfterDelete (5.95s) === RUN TestCopyRedownload run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zevijan8roce'", Local "Local file system at /tmp/rclone2511166019", Modify Window "1ms" 2025/05/14 03:22:17 DEBUG : sub dir/hello world: md5 = a4d63639472706b7c2ca294531575232 OK 2025/05/14 03:22:18 DEBUG : Added delayed dir = "sub dir", newDst= 2025/05/14 03:22:18 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2025/05/14 03:22:18 DEBUG : Local file system at /tmp/rclone2511166019: Waiting for checks to finish 2025/05/14 03:22:18 DEBUG : Local file system at /tmp/rclone2511166019: Waiting for transfers to finish 2025/05/14 03:22:18 DEBUG : sub dir/hello world.285f0a30.partial: renamed to: sub dir/hello world 2025/05/14 03:22:18 INFO : sub dir/hello world: Copied (new) 2025/05/14 03:22:18 INFO : sub dir: Set directory modification time (using DirSetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zevijan8roce'", Local "Local file system at /tmp/rclone2511166019", Modify Window "1ms" 2025/05/14 03:22:20 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestCopyRedownload (6.23s) === RUN TestSyncBasedOnCheckSum run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zevijan8roce'", Local "Local file system at /tmp/rclone2511166019", Modify Window "1ms" 2025/05/14 03:22:21 DEBUG : check sum: Need to transfer - File not found at Destination 2025/05/14 03:22:21 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zevijan8roce': Waiting for checks to finish 2025/05/14 03:22:21 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zevijan8roce': Waiting for transfers to finish 2025/05/14 03:22:22 DEBUG : check sum: md5 = 9e1a0caec97b11b374ee81915fea64e3 OK 2025/05/14 03:22:22 INFO : check sum: Copied (new) 2025/05/14 03:22:22 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zevijan8roce'", Local "Local file system at /tmp/rclone2511166019", Modify Window "1ms" 2025/05/14 03:22:23 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zevijan8roce': Waiting for checks to finish 2025/05/14 03:22:23 NOTICE: Encrypted drive 'TestCryptDrive:rclone-test-zevijan8roce': --checksum is in use but the source and destination have no hashes in common; falling back to --size-only 2025/05/14 03:22:23 DEBUG : check sum: Size of src and dst objects identical 2025/05/14 03:22:23 DEBUG : check sum: Unchanged skipping 2025/05/14 03:22:23 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zevijan8roce': Waiting for transfers to finish 2025/05/14 03:22:23 DEBUG : Waiting for deletions to finish 2025/05/14 03:22:23 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zevijan8roce'", Local "Local file system at /tmp/rclone2511166019", Modify Window "1ms" --- PASS: TestSyncBasedOnCheckSum (4.51s) === RUN TestSyncSizeOnly run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zevijan8roce'", Local "Local file system at /tmp/rclone2511166019", Modify Window "1ms" 2025/05/14 03:22:26 DEBUG : sizeonly: Need to transfer - File not found at Destination 2025/05/14 03:22:26 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zevijan8roce': Waiting for checks to finish 2025/05/14 03:22:26 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zevijan8roce': Waiting for transfers to finish 2025/05/14 03:22:27 DEBUG : sizeonly: md5 = 013da94ffe4941711e8ab9f598c50a85 OK 2025/05/14 03:22:27 INFO : sizeonly: Copied (new) 2025/05/14 03:22:27 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zevijan8roce'", Local "Local file system at /tmp/rclone2511166019", Modify Window "1ms" 2025/05/14 03:22:27 DEBUG : sizeonly: Sizes identical 2025/05/14 03:22:27 DEBUG : sizeonly: Unchanged skipping 2025/05/14 03:22:27 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zevijan8roce': Waiting for checks to finish 2025/05/14 03:22:27 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zevijan8roce': Waiting for transfers to finish 2025/05/14 03:22:27 DEBUG : Waiting for deletions to finish 2025/05/14 03:22:27 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zevijan8roce'", Local "Local file system at /tmp/rclone2511166019", Modify Window "1ms" --- PASS: TestSyncSizeOnly (4.32s) === RUN TestSyncIgnoreSize run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zevijan8roce'", Local "Local file system at /tmp/rclone2511166019", Modify Window "1ms" 2025/05/14 03:22:30 DEBUG : ignore-size: Need to transfer - File not found at Destination 2025/05/14 03:22:30 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zevijan8roce': Waiting for checks to finish 2025/05/14 03:22:30 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zevijan8roce': Waiting for transfers to finish 2025/05/14 03:22:31 DEBUG : ignore-size: md5 = dbfa00b0b55b6b547f52c6d9bc3e7df3 OK 2025/05/14 03:22:31 INFO : ignore-size: Copied (new) 2025/05/14 03:22:31 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zevijan8roce'", Local "Local file system at /tmp/rclone2511166019", Modify Window "1ms" 2025/05/14 03:22:32 DEBUG : ignore-size: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/05/14 03:22:32 DEBUG : ignore-size: Unchanged skipping 2025/05/14 03:22:32 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zevijan8roce': Waiting for checks to finish 2025/05/14 03:22:32 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zevijan8roce': Waiting for transfers to finish 2025/05/14 03:22:32 DEBUG : Waiting for deletions to finish 2025/05/14 03:22:32 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zevijan8roce'", Local "Local file system at /tmp/rclone2511166019", Modify Window "1ms" --- PASS: TestSyncIgnoreSize (4.22s) === RUN TestSyncIgnoreTimes run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zevijan8roce'", Local "Local file system at /tmp/rclone2511166019", Modify Window "1ms" 2025/05/14 03:22:35 DEBUG : existing: md5 = c5fcadf20c27ad78c9fe4c64db17d870 OK 2025/05/14 03:22:36 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zevijan8roce': Waiting for checks to finish 2025/05/14 03:22:36 DEBUG : existing: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/05/14 03:22:36 DEBUG : existing: Unchanged skipping 2025/05/14 03:22:36 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zevijan8roce': Waiting for transfers to finish 2025/05/14 03:22:36 DEBUG : Waiting for deletions to finish 2025/05/14 03:22:36 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zevijan8roce'", Local "Local file system at /tmp/rclone2511166019", Modify Window "1ms" 2025/05/14 03:22:36 DEBUG : existing: Transferring unconditionally as --ignore-times is in use 2025/05/14 03:22:36 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zevijan8roce': Waiting for checks to finish 2025/05/14 03:22:36 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zevijan8roce': Waiting for transfers to finish 2025/05/14 03:22:37 DEBUG : existing: md5 = 4a4e85c463f2799c13867a63e830ba9e OK 2025/05/14 03:22:37 INFO : existing: Copied (replaced existing) 2025/05/14 03:22:37 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zevijan8roce'", Local "Local file system at /tmp/rclone2511166019", Modify Window "1ms" --- PASS: TestSyncIgnoreTimes (5.38s) === RUN TestSyncIgnoreExisting run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zevijan8roce'", Local "Local file system at /tmp/rclone2511166019", Modify Window "1ms" 2025/05/14 03:22:39 DEBUG : existing: Need to transfer - File not found at Destination 2025/05/14 03:22:39 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zevijan8roce': Waiting for checks to finish 2025/05/14 03:22:39 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zevijan8roce': Waiting for transfers to finish 2025/05/14 03:22:41 DEBUG : existing: md5 = 82d440af8aaebbbebe4c3069fe1a5f1a OK 2025/05/14 03:22:41 INFO : existing: Copied (new) 2025/05/14 03:22:41 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zevijan8roce'", Local "Local file system at /tmp/rclone2511166019", Modify Window "1ms" 2025/05/14 03:22:42 DEBUG : existing: Destination exists, skipping 2025/05/14 03:22:42 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zevijan8roce': Waiting for checks to finish 2025/05/14 03:22:42 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zevijan8roce': Waiting for transfers to finish 2025/05/14 03:22:42 DEBUG : Waiting for deletions to finish 2025/05/14 03:22:42 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zevijan8roce'", Local "Local file system at /tmp/rclone2511166019", Modify Window "1ms" --- PASS: TestSyncIgnoreExisting (4.46s) === RUN TestSyncIgnoreErrors run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zevijan8roce'", Local "Local file system at /tmp/rclone2511166019", Modify Window "1ms" 2025/05/14 03:22:46 DEBUG : b/potato: md5 = dbade001ae1d323028bd290f07d2aefd OK 2025/05/14 03:22:48 DEBUG : c/non empty space: md5 = 1eecc04ddb6dcb3381d1d63fed2e0837 OK 2025/05/14 03:22:48 INFO : d: Making directory 2025/05/14 03:22:50 DEBUG : Added delayed dir = "a", newDst= 2025/05/14 03:22:50 INFO : c: Set directory modification time (using SetModTime) 2025/05/14 03:22:50 DEBUG : Added delayed dir = "c", newDst=c 2025/05/14 03:22:50 DEBUG : c/non empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/05/14 03:22:50 DEBUG : a/potato2: Need to transfer - File not found at Destination 2025/05/14 03:22:50 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zevijan8roce': Waiting for checks to finish 2025/05/14 03:22:50 DEBUG : c/non empty space: Unchanged skipping 2025/05/14 03:22:50 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zevijan8roce': Waiting for transfers to finish 2025/05/14 03:22:52 DEBUG : a/potato2: md5 = 945261b56c4331029c5f1241a3e7a67b OK 2025/05/14 03:22:52 INFO : a/potato2: Copied (new) 2025/05/14 03:22:52 DEBUG : Waiting for deletions to finish 2025/05/14 03:22:53 INFO : b/potato: Deleted 2025/05/14 03:22:53 INFO : a: Set directory modification time (using DirSetModTime) 2025/05/14 03:22:53 INFO : d: Removing directory 2025/05/14 03:22:54 INFO : b: Removing directory 2025/05/14 03:22:54 DEBUG : 32d8ua6196mc1r7qkfog53rkg0: Rmdir: contains trashed file: "2m507n64kafsi59v9q71r281a4" 2025/05/14 03:22:55 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zevijan8roce': deleted 2 directories run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zevijan8roce'", Local "Local file system at /tmp/rclone2511166019", Modify Window "1ms" 2025/05/14 03:22:57 DEBUG : 3i9du405pfogq3ncai6pg7ouio: Rmdir: contains trashed file: "982d3pss7t5pn0il16r2foj31s" 2025/05/14 03:22:57 DEBUG : 2bsvlrk2ne1lfitm6tttcu0qt8: Rmdir: contains trashed file: "89l8renevh3mji1c8r1p7qn6tg" --- PASS: TestSyncIgnoreErrors (14.75s) === RUN TestSyncAfterChangingModtimeOnly run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zevijan8roce'", Local "Local file system at /tmp/rclone2511166019", Modify Window "1ms" 2025/05/14 03:23:00 DEBUG : empty space: md5 = 11b11522dbea79003cdffa63be734fbe OK 2025/05/14 03:23:00 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/05/14 03:23:00 NOTICE: empty space: Skipped copy as --dry-run is set (size 1) 2025/05/14 03:23:00 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zevijan8roce': Waiting for checks to finish 2025/05/14 03:23:00 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zevijan8roce': Waiting for transfers to finish 2025/05/14 03:23:00 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zevijan8roce'", Local "Local file system at /tmp/rclone2511166019", Modify Window "1ms" 2025/05/14 03:23:01 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zevijan8roce': Waiting for checks to finish 2025/05/14 03:23:01 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/05/14 03:23:01 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zevijan8roce': Waiting for transfers to finish 2025/05/14 03:23:02 DEBUG : empty space: md5 = c43e0d5c076f077bc821763365a2ee91 OK 2025/05/14 03:23:02 INFO : empty space: Copied (replaced existing) 2025/05/14 03:23:02 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zevijan8roce'", Local "Local file system at /tmp/rclone2511166019", Modify Window "1ms" --- PASS: TestSyncAfterChangingModtimeOnly (5.74s) === RUN TestSyncAfterChangingModtimeOnlyWithNoUpdateModTime run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zevijan8roce'", Local "Local file system at /tmp/rclone2511166019", Modify Window "1ms" sync_test.go:1016: Can't check this if no hashes supported --- PASS: TestSyncAfterChangingModtimeOnlyWithNoUpdateModTime (0.44s) === RUN TestSyncDoesntUpdateModtime run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zevijan8roce'", Local "Local file system at /tmp/rclone2511166019", Modify Window "1ms" 2025/05/14 03:23:06 DEBUG : foo: md5 = c30a50f67fdf7f2b9278014e0dc4f3eb OK 2025/05/14 03:23:06 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zevijan8roce': Waiting for checks to finish 2025/05/14 03:23:06 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/05/14 03:23:06 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zevijan8roce': Waiting for transfers to finish 2025/05/14 03:23:08 DEBUG : foo: md5 = b08f8e247778b1771e0750b787406ba8 OK 2025/05/14 03:23:08 INFO : foo: Copied (replaced existing) 2025/05/14 03:23:08 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zevijan8roce'", Local "Local file system at /tmp/rclone2511166019", Modify Window "1ms" --- PASS: TestSyncDoesntUpdateModtime (4.67s) === RUN TestSyncAfterAddingAFile run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zevijan8roce'", Local "Local file system at /tmp/rclone2511166019", Modify Window "1ms" 2025/05/14 03:23:11 DEBUG : empty space: md5 = aee9a952a858e179cdc2b82600ab1f6f OK 2025/05/14 03:23:11 DEBUG : empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/05/14 03:23:11 DEBUG : potato: Need to transfer - File not found at Destination 2025/05/14 03:23:11 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zevijan8roce': Waiting for checks to finish 2025/05/14 03:23:11 DEBUG : empty space: Unchanged skipping 2025/05/14 03:23:11 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zevijan8roce': Waiting for transfers to finish 2025/05/14 03:23:13 DEBUG : potato: md5 = ffd0b5b82a2a91499032b014bfa5f4d0 OK 2025/05/14 03:23:13 INFO : potato: Copied (new) 2025/05/14 03:23:13 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zevijan8roce'", Local "Local file system at /tmp/rclone2511166019", Modify Window "1ms" --- PASS: TestSyncAfterAddingAFile (5.43s) === RUN TestSyncAfterChangingFilesSizeOnly run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zevijan8roce'", Local "Local file system at /tmp/rclone2511166019", Modify Window "1ms" 2025/05/14 03:23:16 DEBUG : potato: md5 = 9677a7873156c79e713251960b96c20f OK 2025/05/14 03:23:17 DEBUG : potato: Sizes differ (src 21 vs dst 60) 2025/05/14 03:23:17 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zevijan8roce': Waiting for checks to finish 2025/05/14 03:23:17 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zevijan8roce': Waiting for transfers to finish 2025/05/14 03:23:18 DEBUG : potato: md5 = 1843e040849afbc475a39dc044e8f7eb OK 2025/05/14 03:23:18 INFO : potato: Copied (replaced existing) 2025/05/14 03:23:18 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zevijan8roce'", Local "Local file system at /tmp/rclone2511166019", Modify Window "1ms" --- PASS: TestSyncAfterChangingFilesSizeOnly (5.14s) === RUN TestSyncAfterChangingContentsOnly run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zevijan8roce'", Local "Local file system at /tmp/rclone2511166019", Modify Window "1ms" 2025/05/14 03:23:21 DEBUG : potato: md5 = 936faf9010983f8cc17c33c70f5a71b7 OK 2025/05/14 03:23:22 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/05/14 03:23:22 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zevijan8roce': Waiting for checks to finish 2025/05/14 03:23:22 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zevijan8roce': Waiting for transfers to finish 2025/05/14 03:23:23 DEBUG : potato: md5 = 98dfd618abb84ffad86f604d276d91af OK 2025/05/14 03:23:23 INFO : potato: Copied (replaced existing) 2025/05/14 03:23:23 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zevijan8roce'", Local "Local file system at /tmp/rclone2511166019", Modify Window "1ms" --- PASS: TestSyncAfterChangingContentsOnly (4.86s) === RUN TestSyncAfterRemovingAFileAndAddingAFileDryRun run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zevijan8roce'", Local "Local file system at /tmp/rclone2511166019", Modify Window "1ms" 2025/05/14 03:23:26 DEBUG : potato: md5 = b1ca1fb825b936f9cbb711eef451be1f OK 2025/05/14 03:23:27 DEBUG : empty space: md5 = c1d4d648cf3303db8947ef58c5a97474 OK 2025/05/14 03:23:28 DEBUG : potato2: Need to transfer - File not found at Destination 2025/05/14 03:23:28 DEBUG : empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/05/14 03:23:28 DEBUG : empty space: Unchanged skipping 2025/05/14 03:23:28 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zevijan8roce': Waiting for checks to finish 2025/05/14 03:23:28 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zevijan8roce': Waiting for transfers to finish 2025/05/14 03:23:28 NOTICE: potato2: Skipped copy as --dry-run is set (size 60) 2025/05/14 03:23:28 DEBUG : Waiting for deletions to finish 2025/05/14 03:23:28 NOTICE: potato: Skipped delete as --dry-run is set (size 21) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zevijan8roce'", Local "Local file system at /tmp/rclone2511166019", Modify Window "1ms" --- PASS: TestSyncAfterRemovingAFileAndAddingAFileDryRun (5.22s) === RUN TestSyncAfterRemovingAFileAndAddingAFile run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zevijan8roce'", Local "Local file system at /tmp/rclone2511166019", Modify Window "1ms" 2025/05/14 03:23:31 DEBUG : potato: md5 = 86e7462fe5b655e11ab8c0c08bb294d3 OK 2025/05/14 03:23:33 DEBUG : empty space: md5 = 0dce02437734c43db5b728b0eb95eaa4 OK 2025/05/14 03:23:33 DEBUG : empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/05/14 03:23:33 DEBUG : potato2: Need to transfer - File not found at Destination 2025/05/14 03:23:33 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zevijan8roce': Waiting for checks to finish 2025/05/14 03:23:33 DEBUG : empty space: Unchanged skipping 2025/05/14 03:23:33 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zevijan8roce': Waiting for transfers to finish 2025/05/14 03:23:35 DEBUG : potato2: md5 = 68253ff45ba2440638fbf2793b7567a9 OK 2025/05/14 03:23:35 INFO : potato2: Copied (new) 2025/05/14 03:23:35 DEBUG : Waiting for deletions to finish 2025/05/14 03:23:35 INFO : potato: Deleted run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zevijan8roce'", Local "Local file system at /tmp/rclone2511166019", Modify Window "1ms" --- PASS: TestSyncAfterRemovingAFileAndAddingAFile (7.39s) === RUN TestSyncAfterRemovingAFileAndAddingAFileSubDir run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zevijan8roce'", Local "Local file system at /tmp/rclone2511166019", Modify Window "1ms" 2025/05/14 03:23:39 DEBUG : b/potato: md5 = b1bf4cc7b43c4d0d6cd945d5d12e465d OK 2025/05/14 03:23:42 DEBUG : c/non empty space: md5 = cacbb14fe8f4e1649c4eab2eb8ea4b6e OK 2025/05/14 03:23:42 INFO : d: Making directory 2025/05/14 03:23:42 INFO : d/e: Making directory 2025/05/14 03:23:45 DEBUG : Added delayed dir = "a", newDst= 2025/05/14 03:23:45 INFO : c: Set directory modification time (using SetModTime) 2025/05/14 03:23:45 DEBUG : Added delayed dir = "c", newDst=c 2025/05/14 03:23:45 DEBUG : c/non empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/05/14 03:23:45 DEBUG : a/potato2: Need to transfer - File not found at Destination 2025/05/14 03:23:45 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zevijan8roce': Waiting for checks to finish 2025/05/14 03:23:45 DEBUG : c/non empty space: Unchanged skipping 2025/05/14 03:23:45 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zevijan8roce': Waiting for transfers to finish 2025/05/14 03:23:48 DEBUG : a/potato2: md5 = 4097171f9d91ada50164644e24982d9a OK 2025/05/14 03:23:48 INFO : a/potato2: Copied (new) 2025/05/14 03:23:48 DEBUG : Waiting for deletions to finish 2025/05/14 03:23:48 INFO : b/potato: Deleted 2025/05/14 03:23:49 INFO : a: Set directory modification time (using DirSetModTime) 2025/05/14 03:23:49 INFO : d/e: Removing directory 2025/05/14 03:23:49 INFO : d: Removing directory 2025/05/14 03:23:50 DEBUG : ka6id8d20d3s5ktapedlphgta8: Rmdir: contains trashed file: "r8sppajuabeak3sbgj2ak8vuf8" 2025/05/14 03:23:50 INFO : b: Removing directory 2025/05/14 03:23:50 DEBUG : 32d8ua6196mc1r7qkfog53rkg0: Rmdir: contains trashed file: "2m507n64kafsi59v9q71r281a4" 2025/05/14 03:23:51 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zevijan8roce': deleted 3 directories run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zevijan8roce'", Local "Local file system at /tmp/rclone2511166019", Modify Window "1ms" 2025/05/14 03:23:53 DEBUG : 3i9du405pfogq3ncai6pg7ouio: Rmdir: contains trashed file: "982d3pss7t5pn0il16r2foj31s" 2025/05/14 03:23:54 DEBUG : 2bsvlrk2ne1lfitm6tttcu0qt8: Rmdir: contains trashed file: "89l8renevh3mji1c8r1p7qn6tg" --- PASS: TestSyncAfterRemovingAFileAndAddingAFileSubDir (17.70s) === RUN TestSyncAfterRemovingAFileAndAddingAFileSubDirWithErrors run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zevijan8roce'", Local "Local file system at /tmp/rclone2511166019", Modify Window "1ms" 2025/05/14 03:23:57 DEBUG : b/potato: md5 = d3de08b47d469547d605d3dd6ea98f46 OK 2025/05/14 03:24:00 DEBUG : c/non empty space: md5 = a02cf1a0e123fd1680033ba4a3481d91 OK 2025/05/14 03:24:00 INFO : d: Making directory 2025/05/14 03:24:01 DEBUG : Added delayed dir = "a", newDst= 2025/05/14 03:24:02 INFO : c: Set directory modification time (using SetModTime) 2025/05/14 03:24:02 DEBUG : Added delayed dir = "c", newDst=c 2025/05/14 03:24:02 DEBUG : c/non empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/05/14 03:24:02 DEBUG : a/potato2: Need to transfer - File not found at Destination 2025/05/14 03:24:02 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zevijan8roce': Waiting for checks to finish 2025/05/14 03:24:02 DEBUG : c/non empty space: Unchanged skipping 2025/05/14 03:24:02 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zevijan8roce': Waiting for transfers to finish 2025/05/14 03:24:04 DEBUG : a/potato2: md5 = 88b3929a43e4f531e0595972200fa7a6 OK 2025/05/14 03:24:04 INFO : a/potato2: Copied (new) 2025/05/14 03:24:04 ERROR : Encrypted drive 'TestCryptDrive:rclone-test-zevijan8roce': not deleting files as there were IO errors 2025/05/14 03:24:04 INFO : a: Set directory modification time (using DirSetModTime) 2025/05/14 03:24:04 ERROR : Encrypted drive 'TestCryptDrive:rclone-test-zevijan8roce': not deleting directories as there were IO errors run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zevijan8roce'", Local "Local file system at /tmp/rclone2511166019", Modify Window "1ms" 2025/05/14 03:24:08 DEBUG : 3i9du405pfogq3ncai6pg7ouio: Rmdir: contains trashed file: "982d3pss7t5pn0il16r2foj31s" 2025/05/14 03:24:08 DEBUG : 32d8ua6196mc1r7qkfog53rkg0: Rmdir: contains trashed file: "2m507n64kafsi59v9q71r281a4" 2025/05/14 03:24:09 DEBUG : 2bsvlrk2ne1lfitm6tttcu0qt8: Rmdir: contains trashed file: "89l8renevh3mji1c8r1p7qn6tg" --- PASS: TestSyncAfterRemovingAFileAndAddingAFileSubDirWithErrors (14.85s) === RUN TestSyncDeleteAfter --- PASS: TestSyncDeleteAfter (0.00s) === RUN TestSyncDeleteDuring run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zevijan8roce'", Local "Local file system at /tmp/rclone2511166019", Modify Window "1ms" 2025/05/14 03:24:11 DEBUG : potato: md5 = 8bbb9a18122c9c3785fe0bcf9d717b6d OK 2025/05/14 03:24:13 DEBUG : empty space: md5 = 7b5ab4dc4d0c597e0c47ad9d1b7abc29 OK 2025/05/14 03:24:13 DEBUG : Waiting for deletions to finish 2025/05/14 03:24:13 DEBUG : empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/05/14 03:24:13 DEBUG : potato2: Need to transfer - File not found at Destination 2025/05/14 03:24:13 DEBUG : empty space: Unchanged skipping 2025/05/14 03:24:13 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zevijan8roce': Waiting for checks to finish 2025/05/14 03:24:13 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zevijan8roce': Waiting for transfers to finish 2025/05/14 03:24:14 INFO : potato: Deleted 2025/05/14 03:24:15 DEBUG : potato2: md5 = 9deed12e2fc25ad7270b004be6abd0f4 OK 2025/05/14 03:24:15 INFO : potato2: Copied (new) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zevijan8roce'", Local "Local file system at /tmp/rclone2511166019", Modify Window "1ms" --- PASS: TestSyncDeleteDuring (6.84s) === RUN TestSyncDeleteBefore run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zevijan8roce'", Local "Local file system at /tmp/rclone2511166019", Modify Window "1ms" 2025/05/14 03:24:18 DEBUG : potato: md5 = c633975a34129bf267761d651bfa9b5a OK 2025/05/14 03:24:19 DEBUG : empty space: md5 = e457a16da556b1e61104778bcd041d44 OK 2025/05/14 03:24:19 DEBUG : Waiting for deletions to finish 2025/05/14 03:24:20 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zevijan8roce': Waiting for checks to finish 2025/05/14 03:24:20 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zevijan8roce': Waiting for transfers to finish 2025/05/14 03:24:20 INFO : potato: Deleted 2025/05/14 03:24:21 DEBUG : empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/05/14 03:24:21 DEBUG : potato2: Need to transfer - File not found at Destination 2025/05/14 03:24:21 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zevijan8roce': Waiting for checks to finish 2025/05/14 03:24:21 DEBUG : empty space: Unchanged skipping 2025/05/14 03:24:21 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zevijan8roce': Waiting for transfers to finish 2025/05/14 03:24:22 DEBUG : potato2: md5 = bb424c8d15ec52dc029797f6ecc11430 OK 2025/05/14 03:24:22 INFO : potato2: Copied (new) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zevijan8roce'", Local "Local file system at /tmp/rclone2511166019", Modify Window "1ms" --- PASS: TestSyncDeleteBefore (7.49s) === RUN TestCopyDeleteBefore run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zevijan8roce'", Local "Local file system at /tmp/rclone2511166019", Modify Window "1ms" 2025/05/14 03:24:26 DEBUG : potato: md5 = 40673c702262892366b483fb78fad30d OK 2025/05/14 03:24:26 DEBUG : potato2: Need to transfer - File not found at Destination 2025/05/14 03:24:26 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zevijan8roce': Waiting for checks to finish 2025/05/14 03:24:26 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zevijan8roce': Waiting for transfers to finish 2025/05/14 03:24:27 DEBUG : potato2: md5 = f868af41bd1258130038775be2dc15c4 OK 2025/05/14 03:24:27 INFO : potato2: Copied (new) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zevijan8roce'", Local "Local file system at /tmp/rclone2511166019", Modify Window "1ms" --- PASS: TestCopyDeleteBefore (5.29s) === RUN TestSyncWithExclude run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zevijan8roce'", Local "Local file system at /tmp/rclone2511166019", Modify Window "1ms" 2025/05/14 03:24:31 DEBUG : potato2: md5 = 7e3c3031bad34d23795f0b464cd7023f OK 2025/05/14 03:24:32 DEBUG : empty space: md5 = a1d20b72bb087448da1fc2305b512226 OK 2025/05/14 03:24:32 DEBUG : enormous: Excluded (Size Filter) 2025/05/14 03:24:32 DEBUG : enormous: Excluded 2025/05/14 03:24:32 DEBUG : potato2: Excluded (Size Filter) 2025/05/14 03:24:32 DEBUG : potato2: Excluded 2025/05/14 03:24:33 DEBUG : potato2: Excluded (Size Filter) 2025/05/14 03:24:33 DEBUG : empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/05/14 03:24:33 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zevijan8roce': Waiting for checks to finish 2025/05/14 03:24:33 DEBUG : empty space: Unchanged skipping 2025/05/14 03:24:33 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zevijan8roce': Waiting for transfers to finish 2025/05/14 03:24:33 DEBUG : Waiting for deletions to finish 2025/05/14 03:24:33 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zevijan8roce'", Local "Local file system at /tmp/rclone2511166019", Modify Window "1ms" 2025/05/14 03:24:33 DEBUG : enormous: Excluded (Size Filter) 2025/05/14 03:24:33 DEBUG : enormous: Excluded 2025/05/14 03:24:33 DEBUG : potato2: Excluded (Size Filter) 2025/05/14 03:24:33 DEBUG : potato2: Excluded 2025/05/14 03:24:33 DEBUG : potato2: Excluded (Size Filter) 2025/05/14 03:24:33 DEBUG : empty space: Size and modification time the same (differ by 456.789µs, within tolerance 1ms) 2025/05/14 03:24:33 DEBUG : empty space: Unchanged skipping 2025/05/14 03:24:33 DEBUG : Local file system at /tmp/rclone2511166019: Waiting for checks to finish 2025/05/14 03:24:33 DEBUG : Local file system at /tmp/rclone2511166019: Waiting for transfers to finish 2025/05/14 03:24:33 DEBUG : Waiting for deletions to finish 2025/05/14 03:24:33 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zevijan8roce'", Local "Local file system at /tmp/rclone2511166019", Modify Window "1ms" --- PASS: TestSyncWithExclude (5.95s) === RUN TestSyncWithExcludeAndDeleteExcluded run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zevijan8roce'", Local "Local file system at /tmp/rclone2511166019", Modify Window "1ms" 2025/05/14 03:24:37 DEBUG : potato2: md5 = 1f3b9e7721a2bc408f650673afde14a0 OK 2025/05/14 03:24:38 DEBUG : empty space: md5 = c944c7440cbc5646b33678ffe6a8c3ff OK 2025/05/14 03:24:40 DEBUG : enormous: md5 = 161ebedae161d6933dd0642ab3831cd7 OK 2025/05/14 03:24:40 DEBUG : enormous: Excluded (Size Filter) 2025/05/14 03:24:40 DEBUG : enormous: Excluded 2025/05/14 03:24:40 DEBUG : potato2: Excluded (Size Filter) 2025/05/14 03:24:40 DEBUG : potato2: Excluded 2025/05/14 03:24:40 DEBUG : empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/05/14 03:24:40 DEBUG : empty space: Unchanged skipping 2025/05/14 03:24:40 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zevijan8roce': Waiting for checks to finish 2025/05/14 03:24:40 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zevijan8roce': Waiting for transfers to finish 2025/05/14 03:24:40 DEBUG : Waiting for deletions to finish 2025/05/14 03:24:41 INFO : potato2: Deleted 2025/05/14 03:24:41 INFO : enormous: Deleted 2025/05/14 03:24:41 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zevijan8roce'", Local "Local file system at /tmp/rclone2511166019", Modify Window "1ms" 2025/05/14 03:24:41 DEBUG : empty space: Size and modification time the same (differ by 456.789µs, within tolerance 1ms) 2025/05/14 03:24:41 DEBUG : Local file system at /tmp/rclone2511166019: Waiting for checks to finish 2025/05/14 03:24:41 DEBUG : empty space: Unchanged skipping 2025/05/14 03:24:41 DEBUG : Local file system at /tmp/rclone2511166019: Waiting for transfers to finish 2025/05/14 03:24:41 DEBUG : Waiting for deletions to finish 2025/05/14 03:24:41 INFO : enormous: Deleted 2025/05/14 03:24:41 INFO : potato2: Deleted 2025/05/14 03:24:41 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zevijan8roce'", Local "Local file system at /tmp/rclone2511166019", Modify Window "1ms" --- PASS: TestSyncWithExcludeAndDeleteExcluded (7.34s) === RUN TestSyncWithUpdateOlder run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zevijan8roce'", Local "Local file system at /tmp/rclone2511166019", Modify Window "1ms" 2025/05/14 03:24:44 DEBUG : one: md5 = b4af3948091bfc455389b3c932219943 OK 2025/05/14 03:24:45 DEBUG : two: md5 = b04faae1d71220bab143e0a4a3a79df9 OK 2025/05/14 03:24:47 DEBUG : three: md5 = 6aba149ae1d463182a350e35190175b2 OK 2025/05/14 03:24:48 DEBUG : four: md5 = 54b0a9d2108a72bd1bed8d7401d6fd29 OK 2025/05/14 03:24:49 DEBUG : five: Need to transfer - File not found at Destination 2025/05/14 03:24:49 DEBUG : four: Sizes differ (src 4 vs dst 8) 2025/05/14 03:24:49 DEBUG : four: Destination mod time is within 1s of source but files differ, transferring 2025/05/14 03:24:49 DEBUG : one: Destination is newer than source, skipping 2025/05/14 03:24:49 DEBUG : three: Sizes identical 2025/05/14 03:24:49 DEBUG : three: Destination mod time is within 1s of source and files identical, skipping 2025/05/14 03:24:49 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zevijan8roce': Waiting for checks to finish 2025/05/14 03:24:49 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zevijan8roce': Waiting for transfers to finish 2025/05/14 03:24:50 DEBUG : two: md5 = a58b99ad880e71021d0e218c83c2acc3 OK 2025/05/14 03:24:50 INFO : two: Copied (replaced existing) 2025/05/14 03:24:50 DEBUG : four: md5 = c0a4c73d2414d09d6ff168a9be466fbd OK 2025/05/14 03:24:50 INFO : four: Copied (replaced existing) 2025/05/14 03:24:50 DEBUG : five: md5 = e4df5fd51f8387dbfe988fefdb77496f OK 2025/05/14 03:24:50 INFO : five: Copied (new) 2025/05/14 03:24:50 DEBUG : Waiting for deletions to finish sync_test.go:1449: Skip test with --checksum as no hashes supported --- PASS: TestSyncWithUpdateOlder (10.22s) === 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-zevijan8roce'", Local "Local file system at /tmp/rclone2511166019", Modify Window "1ms" sync_test.go:1538: Can track renames: false 2025/05/14 03:24:53 ERROR : Encrypted drive 'TestCryptDrive:rclone-test-zevijan8roce': Ignoring --track-renames as the source and destination do not have a common hash 2025/05/14 03:24:53 DEBUG : potato: Need to transfer - File not found at Destination 2025/05/14 03:24:53 DEBUG : yam: Need to transfer - File not found at Destination 2025/05/14 03:24:53 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zevijan8roce': Waiting for checks to finish 2025/05/14 03:24:53 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zevijan8roce': Waiting for transfers to finish 2025/05/14 03:24:54 DEBUG : potato: md5 = 4c7dec857da7567dfb9f6e2220363861 OK 2025/05/14 03:24:54 INFO : potato: Copied (new) 2025/05/14 03:24:55 DEBUG : yam: md5 = cb305a7153629b4f34e390979bd7e38b OK 2025/05/14 03:24:55 INFO : yam: Copied (new) 2025/05/14 03:24:55 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zevijan8roce'", Local "Local file system at /tmp/rclone2511166019", Modify Window "1ms" 2025/05/14 03:24:55 ERROR : Encrypted drive 'TestCryptDrive:rclone-test-zevijan8roce': Ignoring --track-renames as the source and destination do not have a common hash 2025/05/14 03:24:55 DEBUG : potato: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/05/14 03:24:55 DEBUG : yaml: Need to transfer - File not found at Destination 2025/05/14 03:24:55 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zevijan8roce': Waiting for checks to finish 2025/05/14 03:24:55 DEBUG : potato: Unchanged skipping 2025/05/14 03:24:55 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zevijan8roce': Waiting for transfers to finish 2025/05/14 03:24:56 DEBUG : yaml: md5 = 1b3c3645bbfceaaaa1806db2d4bd8ff6 OK 2025/05/14 03:24:56 INFO : yaml: Copied (new) 2025/05/14 03:24:56 DEBUG : Waiting for deletions to finish 2025/05/14 03:24:57 INFO : yam: Deleted run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zevijan8roce'", Local "Local file system at /tmp/rclone2511166019", Modify Window "1ms" --- PASS: TestSyncWithTrackRenames (6.40s) === RUN TestParseRenamesStrategyModtime --- PASS: TestParseRenamesStrategyModtime (0.00s) === RUN TestRenamesStrategyModtime --- PASS: TestRenamesStrategyModtime (0.00s) === RUN TestSyncWithTrackRenamesStrategyModtime run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zevijan8roce'", Local "Local file system at /tmp/rclone2511166019", Modify Window "1ms" sync_test.go:1610: Can track renames: true 2025/05/14 03:25:00 INFO : Encrypted drive 'TestCryptDrive:rclone-test-zevijan8roce': Making map for --track-renames 2025/05/14 03:25:00 INFO : Encrypted drive 'TestCryptDrive:rclone-test-zevijan8roce': Finished making map for --track-renames 2025/05/14 03:25:00 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zevijan8roce': Waiting for checks to finish 2025/05/14 03:25:00 DEBUG : potato: Need to transfer - No matching file found at Destination 2025/05/14 03:25:00 DEBUG : yam: Need to transfer - No matching file found at Destination 2025/05/14 03:25:00 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zevijan8roce': Waiting for renames to finish 2025/05/14 03:25:00 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zevijan8roce': Waiting for transfers to finish 2025/05/14 03:25:01 DEBUG : yam: md5 = d140076fedae847c4f9f8704611ea6d6 OK 2025/05/14 03:25:01 INFO : yam: Copied (new) 2025/05/14 03:25:01 DEBUG : potato: md5 = f05b354c3b571fd527f72c3a97114e90 OK 2025/05/14 03:25:01 INFO : potato: Copied (new) 2025/05/14 03:25:01 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zevijan8roce'", Local "Local file system at /tmp/rclone2511166019", Modify Window "1ms" 2025/05/14 03:25:02 DEBUG : potato: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/05/14 03:25:02 INFO : Encrypted drive 'TestCryptDrive:rclone-test-zevijan8roce': Making map for --track-renames 2025/05/14 03:25:02 INFO : Encrypted drive 'TestCryptDrive:rclone-test-zevijan8roce': Finished making map for --track-renames 2025/05/14 03:25:02 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zevijan8roce': Waiting for checks to finish 2025/05/14 03:25:02 DEBUG : potato: Unchanged skipping 2025/05/14 03:25:02 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zevijan8roce': Waiting for renames to finish 2025/05/14 03:25:02 INFO : yam: Moved (server-side) to: yaml 2025/05/14 03:25:02 INFO : yaml: Renamed from "yam" 2025/05/14 03:25:02 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zevijan8roce': Waiting for transfers to finish 2025/05/14 03:25:02 DEBUG : Waiting for deletions to finish 2025/05/14 03:25:02 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zevijan8roce'", Local "Local file system at /tmp/rclone2511166019", Modify Window "1ms" --- PASS: TestSyncWithTrackRenamesStrategyModtime (5.29s) === RUN TestSyncWithTrackRenamesStrategyLeaf run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zevijan8roce'", Local "Local file system at /tmp/rclone2511166019", Modify Window "1ms" sync_test.go:1649: Can track renames: true 2025/05/14 03:25:05 DEBUG : Added delayed dir = "sub", newDst= 2025/05/14 03:25:05 INFO : Encrypted drive 'TestCryptDrive:rclone-test-zevijan8roce': Making map for --track-renames 2025/05/14 03:25:05 INFO : Encrypted drive 'TestCryptDrive:rclone-test-zevijan8roce': Finished making map for --track-renames 2025/05/14 03:25:05 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zevijan8roce': Waiting for checks to finish 2025/05/14 03:25:05 DEBUG : potato: Need to transfer - No matching file found at Destination 2025/05/14 03:25:05 DEBUG : sub/yam: Need to transfer - No matching file found at Destination 2025/05/14 03:25:05 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zevijan8roce': Waiting for renames to finish 2025/05/14 03:25:05 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zevijan8roce': Waiting for transfers to finish 2025/05/14 03:25:07 DEBUG : sub/yam: md5 = 4460c73ff2cb6b597a36d4985fca1ffd OK 2025/05/14 03:25:07 INFO : sub/yam: Copied (new) 2025/05/14 03:25:07 DEBUG : potato: md5 = 0996ee1d8a0603a13c699569ba0eb68d OK 2025/05/14 03:25:07 INFO : potato: Copied (new) 2025/05/14 03:25:07 DEBUG : Waiting for deletions to finish 2025/05/14 03:25:08 INFO : sub: Set directory modification time (using DirSetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zevijan8roce'", Local "Local file system at /tmp/rclone2511166019", Modify Window "1ms" 2025/05/14 03:25:09 DEBUG : potato: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/05/14 03:25:09 DEBUG : potato: Unchanged skipping 2025/05/14 03:25:09 INFO : sub: Set directory modification time (using SetModTime) 2025/05/14 03:25:09 DEBUG : Added delayed dir = "sub", newDst=sub 2025/05/14 03:25:09 INFO : Encrypted drive 'TestCryptDrive:rclone-test-zevijan8roce': Making map for --track-renames 2025/05/14 03:25:09 INFO : Encrypted drive 'TestCryptDrive:rclone-test-zevijan8roce': Finished making map for --track-renames 2025/05/14 03:25:09 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zevijan8roce': Waiting for checks to finish 2025/05/14 03:25:09 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zevijan8roce': Waiting for renames to finish 2025/05/14 03:25:10 INFO : sub/yam: Moved (server-side) to: yam 2025/05/14 03:25:10 INFO : yam: Renamed from "sub/yam" 2025/05/14 03:25:10 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zevijan8roce': Waiting for transfers to finish 2025/05/14 03:25:10 DEBUG : Waiting for deletions to finish 2025/05/14 03:25:10 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zevijan8roce'", Local "Local file system at /tmp/rclone2511166019", Modify Window "1ms" --- PASS: TestSyncWithTrackRenamesStrategyLeaf (9.02s) === RUN TestServerSideMoveLocal run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zevijan8roce'", Local "Local file system at /tmp/rclone2511166019", Modify Window "1ms" 2025/05/14 03:25:14 DEBUG : Creating backend with remote "/tmp/rclone2511166019/dir1" 2025/05/14 03:25:14 DEBUG : Creating backend with remote "/tmp/rclone2511166019/dir2" 2025/05/14 03:25:14 DEBUG : Local file system at /tmp/rclone2511166019/dir2: Using server-side directory move 2025/05/14 03:25:14 INFO : Local file system at /tmp/rclone2511166019/dir2: Server side directory move failed - fallback to file moves: can't copy directory - destination already exists 2025/05/14 03:25:14 DEBUG : file1.txt: Need to transfer - File not found at Destination 2025/05/14 03:25:14 DEBUG : Local file system at /tmp/rclone2511166019/dir2: Waiting for checks to finish 2025/05/14 03:25:14 INFO : file1.txt: Moved (server-side) 2025/05/14 03:25:14 DEBUG : Local file system at /tmp/rclone2511166019/dir2: Waiting for transfers to finish --- PASS: TestServerSideMoveLocal (0.44s) === RUN TestMoveWithDeleteEmptySrcDirs run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zevijan8roce'", Local "Local file system at /tmp/rclone2511166019", Modify Window "1ms" 2025/05/14 03:25:14 DEBUG : Added delayed dir = "nested", newDst= 2025/05/14 03:25:14 DEBUG : Added delayed dir = "sub dir", newDst= 2025/05/14 03:25:14 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2025/05/14 03:25:14 DEBUG : Added delayed dir = "nested/sub dir", newDst= 2025/05/14 03:25:14 DEBUG : nested/sub dir/file: Need to transfer - File not found at Destination 2025/05/14 03:25:14 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zevijan8roce': Waiting for checks to finish 2025/05/14 03:25:14 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zevijan8roce': Waiting for transfers to finish 2025/05/14 03:25:17 DEBUG : sub dir/hello world: md5 = b587a775ec9a041179114d61e0af3477 OK 2025/05/14 03:25:17 INFO : sub dir/hello world: Copied (new) 2025/05/14 03:25:17 INFO : sub dir/hello world: Deleted 2025/05/14 03:25:18 DEBUG : nested/sub dir/file: md5 = 429b83fa5f82d84714658dc37a47747c OK 2025/05/14 03:25:18 INFO : nested/sub dir/file: Copied (new) 2025/05/14 03:25:18 INFO : nested/sub dir/file: Deleted 2025/05/14 03:25:19 INFO : nested/sub dir: Set directory modification time (using DirSetModTime) 2025/05/14 03:25:19 INFO : sub dir: Set directory modification time (using DirSetModTime) 2025/05/14 03:25:19 INFO : nested: Set directory modification time (using DirSetModTime) 2025/05/14 03:25:19 INFO : sub dir: Removing directory 2025/05/14 03:25:19 INFO : nested/sub dir: Removing directory 2025/05/14 03:25:19 INFO : nested: Removing directory 2025/05/14 03:25:19 DEBUG : Local file system at /tmp/rclone2511166019: deleted 3 directories run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zevijan8roce'", Local "Local file system at /tmp/rclone2511166019", Modify Window "1ms" 2025/05/14 03:25:22 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" 2025/05/14 03:25:22 DEBUG : 37qp6d1gohacv723ij3brofbu8/14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "ftp4kuv8se7tqduu6pmmcvjsmk" 2025/05/14 03:25:23 DEBUG : 37qp6d1gohacv723ij3brofbu8: Rmdir: contains trashed file: "14begaa36ih249fgrnfk6nulg0" --- PASS: TestMoveWithDeleteEmptySrcDirs (10.03s) === RUN TestMoveWithoutDeleteEmptySrcDirs run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zevijan8roce'", Local "Local file system at /tmp/rclone2511166019", Modify Window "1ms" 2025/05/14 03:25:24 DEBUG : Added delayed dir = "nested", newDst= 2025/05/14 03:25:24 DEBUG : Added delayed dir = "sub dir", newDst= 2025/05/14 03:25:24 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2025/05/14 03:25:24 DEBUG : Added delayed dir = "nested/sub dir", newDst= 2025/05/14 03:25:24 DEBUG : nested/sub dir/file: Need to transfer - File not found at Destination 2025/05/14 03:25:24 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zevijan8roce': Waiting for checks to finish 2025/05/14 03:25:24 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zevijan8roce': Waiting for transfers to finish 2025/05/14 03:25:26 DEBUG : sub dir/hello world: md5 = 3b0e0c17c2804939b63f9d1d6214f32f OK 2025/05/14 03:25:26 INFO : sub dir/hello world: Copied (new) 2025/05/14 03:25:26 INFO : sub dir/hello world: Deleted 2025/05/14 03:25:28 DEBUG : nested/sub dir/file: md5 = 9a21eeb4d96584e65d86befb51c399df OK 2025/05/14 03:25:28 INFO : nested/sub dir/file: Copied (new) 2025/05/14 03:25:28 INFO : nested/sub dir/file: Deleted 2025/05/14 03:25:29 INFO : nested/sub dir: Set directory modification time (using DirSetModTime) 2025/05/14 03:25:29 INFO : sub dir: Set directory modification time (using DirSetModTime) 2025/05/14 03:25:29 INFO : nested: Set directory modification time (using DirSetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zevijan8roce'", Local "Local file system at /tmp/rclone2511166019", Modify Window "1ms" 2025/05/14 03:25:32 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" 2025/05/14 03:25:33 DEBUG : 37qp6d1gohacv723ij3brofbu8/14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "ftp4kuv8se7tqduu6pmmcvjsmk" 2025/05/14 03:25:33 DEBUG : 37qp6d1gohacv723ij3brofbu8: Rmdir: contains trashed file: "14begaa36ih249fgrnfk6nulg0" --- PASS: TestMoveWithoutDeleteEmptySrcDirs (10.32s) === RUN TestMoveWithIgnoreExisting run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zevijan8roce'", Local "Local file system at /tmp/rclone2511166019", Modify Window "1ms" 2025/05/14 03:25:35 DEBUG : existing: Need to transfer - File not found at Destination 2025/05/14 03:25:35 DEBUG : existing-b: Need to transfer - File not found at Destination 2025/05/14 03:25:35 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zevijan8roce': Waiting for checks to finish 2025/05/14 03:25:35 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zevijan8roce': Waiting for transfers to finish 2025/05/14 03:25:36 DEBUG : existing-b: md5 = db647b9c507a1f1a6f07355299bab254 OK 2025/05/14 03:25:36 INFO : existing-b: Copied (new) 2025/05/14 03:25:36 INFO : existing-b: Deleted 2025/05/14 03:25:36 DEBUG : existing: md5 = 217b6ac8a9ebccfaf376199fecbd2a57 OK 2025/05/14 03:25:36 INFO : existing: Copied (new) 2025/05/14 03:25:36 INFO : existing: Deleted 2025/05/14 03:25:37 DEBUG : existing: Destination exists, skipping 2025/05/14 03:25:37 DEBUG : existing: Not removing source file as destination file exists and --ignore-existing is set 2025/05/14 03:25:37 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zevijan8roce': Waiting for checks to finish 2025/05/14 03:25:37 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zevijan8roce': Waiting for transfers to finish 2025/05/14 03:25:37 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zevijan8roce'", Local "Local file system at /tmp/rclone2511166019", Modify Window "1ms" --- PASS: TestMoveWithIgnoreExisting (4.19s) === RUN TestServerSideMove run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zevijan8roce'", Local "Local file system at /tmp/rclone2511166019", Modify Window "1ms" 2025/05/14 03:25:39 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-hitopef2zoli" 2025/05/14 03:25:39 DEBUG : Creating backend with remote "TestDrive:crypt/67it8ao3utpr0qb7nvju9f59nklmv0er94i6aksm2g167oiie33g" 2025/05/14 03:25:41 DEBUG : potato2: md5 = 62df1747eff0af0cc40f0f53abf4af0c OK 2025/05/14 03:25:43 DEBUG : empty space: md5 = 8c0ebc2c3751aea08065949586b90a2a OK 2025/05/14 03:25:44 DEBUG : potato3: md5 = 30cc0d3e527a743ee2a035ac2be93743 OK sync_test.go:1705: Server side move (if possible) Encrypted drive 'TestCryptDrive:rclone-test-zevijan8roce' -> Encrypted drive 'TestCryptDrive:rclone-test-hitopef2zoli' 2025/05/14 03:25:46 DEBUG : empty space: md5 = 8e62c0ac65eddc584a0374ba6e5a61a1 OK 2025/05/14 03:25:47 DEBUG : potato3: md5 = 1ae3c2030a8c1d684a72feca8b60bad8 OK 2025/05/14 03:25:48 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hitopef2zoli': Using server-side directory move 2025/05/14 03:25:48 INFO : Encrypted drive 'TestCryptDrive:rclone-test-hitopef2zoli': Server side directory move failed - fallback to file moves: can't copy directory - destination already exists 2025/05/14 03:25:48 DEBUG : potato2: Need to transfer - File not found at Destination 2025/05/14 03:25:48 DEBUG : empty space: Size and modification time the same (differ by 0s, within tolerance 1ms) 2025/05/14 03:25:48 DEBUG : empty space: Unchanged skipping 2025/05/14 03:25:48 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hitopef2zoli': Waiting for checks to finish 2025/05/14 03:25:48 DEBUG : potato3: Sizes differ (src 68 vs dst 60) 2025/05/14 03:25:48 INFO : empty space: Deleted 2025/05/14 03:25:48 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hitopef2zoli': Waiting for transfers to finish 2025/05/14 03:25:48 INFO : potato3: Deleted 2025/05/14 03:25:49 INFO : potato2: Moved (server-side) 2025/05/14 03:25:49 INFO : potato3: Moved (server-side) 2025/05/14 03:25:49 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-bokepew2peto" 2025/05/14 03:25:50 DEBUG : Creating backend with remote "TestDrive:crypt/scmmk4od7mqr02uj52cdp4i2o345sgcnaiqqafkamq32v1aivttg" 2025/05/14 03:25:50 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-bokepew2peto': Using server-side directory move 2025/05/14 03:25:51 INFO : Encrypted drive 'TestCryptDrive:rclone-test-bokepew2peto': Server side directory move succeeded 2025/05/14 03:25:52 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-bokepew2peto': Purge remote 2025/05/14 03:25:53 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hitopef2zoli': Purge remote 2025/05/14 03:25:53 NOTICE: purge failed: directory not found --- PASS: TestServerSideMove (14.57s) === RUN TestServerSideMoveWithFilter run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zevijan8roce'", Local "Local file system at /tmp/rclone2511166019", Modify Window "1ms" 2025/05/14 03:25:53 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-vaxevip4pehi" 2025/05/14 03:25:53 DEBUG : Creating backend with remote "TestDrive:crypt/osn78h44769ks9nkm23l8i1kmddionrjl2kq36p9bt138f4om0l0" 2025/05/14 03:25:56 DEBUG : potato2: md5 = 70f7c4cb2cdd2262649a3ce4add9cd1a OK 2025/05/14 03:25:57 DEBUG : empty space: md5 = bc612e02a1483c36cf4cfd372d5566bf OK 2025/05/14 03:25:58 DEBUG : potato3: md5 = 1c1edabf969672da28dc2b4884a24239 OK sync_test.go:1705: Server side move (if possible) Encrypted drive 'TestCryptDrive:rclone-test-zevijan8roce' -> Encrypted drive 'TestCryptDrive:rclone-test-vaxevip4pehi' 2025/05/14 03:26:01 DEBUG : empty space: md5 = 02775a3ab2af339115c47ad7eab59d49 OK 2025/05/14 03:26:02 DEBUG : potato3: md5 = 2bac586e33b4adeea7549828a4d07403 OK 2025/05/14 03:26:03 DEBUG : empty space: Excluded (Size Filter) 2025/05/14 03:26:03 DEBUG : empty space: Excluded (Size Filter) 2025/05/14 03:26:03 DEBUG : potato2: Need to transfer - File not found at Destination 2025/05/14 03:26:03 DEBUG : potato3: Sizes differ (src 68 vs dst 60) 2025/05/14 03:26:03 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vaxevip4pehi': Waiting for checks to finish 2025/05/14 03:26:03 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vaxevip4pehi': Waiting for transfers to finish 2025/05/14 03:26:03 INFO : potato3: Deleted 2025/05/14 03:26:03 INFO : potato2: Moved (server-side) 2025/05/14 03:26:04 INFO : potato3: Moved (server-side) 2025/05/14 03:26:04 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-fulanat8sona" 2025/05/14 03:26:04 DEBUG : Creating backend with remote "TestDrive:crypt/hjm3tsheu3enm1pn1jqmkhahineaaoiirtni5iv8qvn7udhbsf5g" 2025/05/14 03:26:05 DEBUG : empty space: Excluded (Size Filter) 2025/05/14 03:26:05 DEBUG : potato2: Need to transfer - File not found at Destination 2025/05/14 03:26:05 DEBUG : potato3: Need to transfer - File not found at Destination 2025/05/14 03:26:05 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-fulanat8sona': Waiting for checks to finish 2025/05/14 03:26:05 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-fulanat8sona': Waiting for transfers to finish 2025/05/14 03:26:07 INFO : potato3: Moved (server-side) 2025/05/14 03:26:07 INFO : potato2: Moved (server-side) 2025/05/14 03:26:08 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-fulanat8sona': Purge remote 2025/05/14 03:26:08 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vaxevip4pehi': Purge remote --- PASS: TestServerSideMoveWithFilter (16.24s) === RUN TestServerSideMoveDeleteEmptySourceDirs run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zevijan8roce'", Local "Local file system at /tmp/rclone2511166019", Modify Window "1ms" 2025/05/14 03:26:09 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-fuyamil8komo" 2025/05/14 03:26:10 DEBUG : Creating backend with remote "TestDrive:crypt/6k6hh60id2lj3ggavqu9ifmat0rgu7fr2p588cded6md7ap3rkt0" 2025/05/14 03:26:12 DEBUG : potato2: md5 = ceeb45df5860510e3dc0b8ab7c5979ac OK 2025/05/14 03:26:13 DEBUG : empty space: md5 = b41606d8927469a87fc9edd30c36bbab OK 2025/05/14 03:26:15 DEBUG : potato3: md5 = 7f74a8647db837318e9d36393681ed67 OK 2025/05/14 03:26:15 INFO : tomatoDir: Making directory sync_test.go:1705: Server side move (if possible) Encrypted drive 'TestCryptDrive:rclone-test-zevijan8roce' -> Encrypted drive 'TestCryptDrive:rclone-test-fuyamil8komo' 2025/05/14 03:26:18 DEBUG : empty space: md5 = ba805b09e52055a857c2d7b77f6f346b OK 2025/05/14 03:26:19 DEBUG : potato3: md5 = e37e380c9d1d90d34568f186e9b0fdaa OK 2025/05/14 03:26:20 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-fuyamil8komo': Using server-side directory move 2025/05/14 03:26:20 INFO : Encrypted drive 'TestCryptDrive:rclone-test-fuyamil8komo': Server side directory move failed - fallback to file moves: can't copy directory - destination already exists 2025/05/14 03:26:20 DEBUG : potato2: Need to transfer - File not found at Destination 2025/05/14 03:26:20 DEBUG : Added delayed dir = "tomatoDir", newDst= 2025/05/14 03:26:20 DEBUG : empty space: Size and modification time the same (differ by 0s, within tolerance 1ms) 2025/05/14 03:26:20 DEBUG : empty space: Unchanged skipping 2025/05/14 03:26:20 DEBUG : potato3: Sizes differ (src 68 vs dst 60) 2025/05/14 03:26:20 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-fuyamil8komo': Waiting for checks to finish 2025/05/14 03:26:20 INFO : empty space: Deleted 2025/05/14 03:26:20 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-fuyamil8komo': Waiting for transfers to finish 2025/05/14 03:26:21 INFO : potato3: Deleted 2025/05/14 03:26:21 INFO : potato2: Moved (server-side) 2025/05/14 03:26:21 INFO : potato3: Moved (server-side) 2025/05/14 03:26:21 INFO : tomatoDir: Removing directory 2025/05/14 03:26:22 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zevijan8roce': deleted 1 directories 2025/05/14 03:26:22 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-hakebah8kewi" 2025/05/14 03:26:23 DEBUG : Creating backend with remote "TestDrive:crypt/eamkc372on54mee3l8msimt7lbt6v8lu63rrbp2cfhu9cm75a6m0" 2025/05/14 03:26:23 INFO : tomatoDir: Making directory 2025/05/14 03:26:24 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hakebah8kewi': Using server-side directory move 2025/05/14 03:26:25 INFO : Encrypted drive 'TestCryptDrive:rclone-test-hakebah8kewi': Server side directory move succeeded 2025/05/14 03:26:26 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hakebah8kewi': Purge remote 2025/05/14 03:26:27 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-fuyamil8komo': Purge remote 2025/05/14 03:26:27 NOTICE: purge failed: directory not found --- PASS: TestServerSideMoveDeleteEmptySourceDirs (17.69s) === RUN TestServerSideMoveOverlap run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zevijan8roce'", Local "Local file system at /tmp/rclone2511166019", Modify Window "1ms" sync_test.go:1910: Skipping test as remote supports DirMove --- SKIP: TestServerSideMoveOverlap (0.41s) === RUN TestSyncOverlap run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zevijan8roce'", Local "Local file system at /tmp/rclone2511166019", Modify Window "1ms" 2025/05/14 03:26:28 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-zevijan8roce/rclone-sync-test" 2025/05/14 03:26:28 DEBUG : Config file has changed externally - reloading 2025/05/14 03:26:28 DEBUG : Creating backend with remote "TestDrive:crypt/ufl16g1kejeblfpcdf7548e43i8hq909bkinusgb0bt9llb2ig7g/i7355aa0sb89uagn75vfjqr6s3e3e1h2et8in57abn1fe8qfego0" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zevijan8roce'", Local "Local file system at /tmp/rclone2511166019", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zevijan8roce'", Local "Local file system at /tmp/rclone2511166019", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zevijan8roce'", Local "Local file system at /tmp/rclone2511166019", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zevijan8roce'", Local "Local file system at /tmp/rclone2511166019", Modify Window "1ms" --- PASS: TestSyncOverlap (3.63s) === RUN TestSyncOverlapWithFilter run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zevijan8roce'", Local "Local file system at /tmp/rclone2511166019", Modify Window "1ms" 2025/05/14 03:26:31 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-zevijan8roce/rclone-sync-test" 2025/05/14 03:26:31 DEBUG : Creating backend with remote "TestDrive:crypt/ufl16g1kejeblfpcdf7548e43i8hq909bkinusgb0bt9llb2ig7g/i7355aa0sb89uagn75vfjqr6s3e3e1h2et8in57abn1fe8qfego0" 2025/05/14 03:26:34 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-zevijan8roce/rclone-sync-test-include/layer2" 2025/05/14 03:26:34 DEBUG : Creating backend with remote "TestDrive:crypt/ufl16g1kejeblfpcdf7548e43i8hq909bkinusgb0bt9llb2ig7g/khf2vlblvnbf9ftevqm0htmss73hj1j5a7q328e4ohrgs7e2loe0/n01jpl9202nn9ec1rb75h0f1c4" 2025/05/14 03:26:36 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-zevijan8roce/rclone-sync-test-ignore-file" 2025/05/14 03:26:36 DEBUG : Creating backend with remote "TestDrive:crypt/ufl16g1kejeblfpcdf7548e43i8hq909bkinusgb0bt9llb2ig7g/kmf11jujl9uha3tjganvgpkn45bu778hb5vb5riug1c26b38k7sg" 2025/05/14 03:26:41 DEBUG : rclone-sync-test-ignore-file/.ignore: md5 = ac1679f85567c5030536f2b54d63438a OK 2025/05/14 03:26:43 DEBUG : Added delayed dir = "rclone-sync-test-include", newDst= 2025/05/14 03:26:43 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zevijan8roce/rclone-sync-test': Waiting for checks to finish 2025/05/14 03:26:43 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zevijan8roce/rclone-sync-test': Waiting for transfers to finish 2025/05/14 03:26:43 DEBUG : Waiting for deletions to finish 2025/05/14 03:26:43 INFO : There was nothing to transfer 2025/05/14 03:26:45 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zevijan8roce': Waiting for checks to finish 2025/05/14 03:26:45 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zevijan8roce': Waiting for transfers to finish 2025/05/14 03:26:45 DEBUG : Waiting for deletions to finish 2025/05/14 03:26:45 INFO : rclone-sync-test-include: Removing directory 2025/05/14 03:26:45 DEBUG : khf2vlblvnbf9ftevqm0htmss73hj1j5a7q328e4ohrgs7e2loe0: Rmdir: contains file: "n01jpl9202nn9ec1rb75h0f1c4" 2025/05/14 03:26:45 DEBUG : rclone-sync-test-include: Failed to Rmdir: directory not empty 2025/05/14 03:26:45 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zevijan8roce': failed to delete 1 directories 2025/05/14 03:26:45 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zevijan8roce'", Local "Local file system at /tmp/rclone2511166019", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zevijan8roce'", Local "Local file system at /tmp/rclone2511166019", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zevijan8roce'", Local "Local file system at /tmp/rclone2511166019", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zevijan8roce'", Local "Local file system at /tmp/rclone2511166019", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zevijan8roce'", Local "Local file system at /tmp/rclone2511166019", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zevijan8roce'", Local "Local file system at /tmp/rclone2511166019", Modify Window "1ms" 2025/05/14 03:26:47 DEBUG : Added delayed dir = "rclone-sync-test-include", newDst= 2025/05/14 03:26:47 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zevijan8roce/rclone-sync-test-include/layer2': Waiting for checks to finish 2025/05/14 03:26:47 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zevijan8roce/rclone-sync-test-include/layer2': Waiting for transfers to finish 2025/05/14 03:26:47 DEBUG : Waiting for deletions to finish 2025/05/14 03:26:47 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zevijan8roce'", Local "Local file system at /tmp/rclone2511166019", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zevijan8roce'", Local "Local file system at /tmp/rclone2511166019", Modify Window "1ms" 2025/05/14 03:26:49 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zevijan8roce': Waiting for checks to finish 2025/05/14 03:26:49 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zevijan8roce': Waiting for transfers to finish 2025/05/14 03:26:49 DEBUG : Waiting for deletions to finish 2025/05/14 03:26:49 INFO : rclone-sync-test-include: Removing directory 2025/05/14 03:26:49 DEBUG : khf2vlblvnbf9ftevqm0htmss73hj1j5a7q328e4ohrgs7e2loe0: Rmdir: contains file: "n01jpl9202nn9ec1rb75h0f1c4" 2025/05/14 03:26:49 DEBUG : rclone-sync-test-include: Failed to Rmdir: directory not empty 2025/05/14 03:26:49 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zevijan8roce': failed to delete 1 directories 2025/05/14 03:26:49 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zevijan8roce'", Local "Local file system at /tmp/rclone2511166019", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zevijan8roce'", Local "Local file system at /tmp/rclone2511166019", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zevijan8roce'", Local "Local file system at /tmp/rclone2511166019", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zevijan8roce'", Local "Local file system at /tmp/rclone2511166019", Modify Window "1ms" 2025/05/14 03:26:51 DEBUG : Added delayed dir = "rclone-sync-test-include", newDst= 2025/05/14 03:26:51 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zevijan8roce/rclone-sync-test-ignore-file': Waiting for checks to finish 2025/05/14 03:26:51 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zevijan8roce/rclone-sync-test-ignore-file': Waiting for transfers to finish 2025/05/14 03:26:51 DEBUG : Waiting for deletions to finish 2025/05/14 03:26:51 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zevijan8roce'", Local "Local file system at /tmp/rclone2511166019", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zevijan8roce'", Local "Local file system at /tmp/rclone2511166019", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zevijan8roce'", Local "Local file system at /tmp/rclone2511166019", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zevijan8roce'", Local "Local file system at /tmp/rclone2511166019", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zevijan8roce'", Local "Local file system at /tmp/rclone2511166019", Modify Window "1ms" 2025/05/14 03:26:53 DEBUG : khf2vlblvnbf9ftevqm0htmss73hj1j5a7q328e4ohrgs7e2loe0: Rmdir: contains trashed file: "n01jpl9202nn9ec1rb75h0f1c4" 2025/05/14 03:26:53 DEBUG : kmf11jujl9uha3tjganvgpkn45bu778hb5vb5riug1c26b38k7sg: Rmdir: contains trashed file: "i0t74httmdlljg425j6tg570d8" --- PASS: TestSyncOverlapWithFilter (31.40s) === RUN TestSyncCompareDest run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zevijan8roce'", Local "Local file system at /tmp/rclone2511166019", Modify Window "1ms" 2025/05/14 03:27:03 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-zevijan8roce/dst" 2025/05/14 03:27:03 DEBUG : Creating backend with remote "TestDrive:crypt/ufl16g1kejeblfpcdf7548e43i8hq909bkinusgb0bt9llb2ig7g/31u3jie661vd5p8j7rtc3hgbh0" 2025/05/14 03:27:04 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-zevijan8roce/CompareDest" 2025/05/14 03:27:04 DEBUG : Creating backend with remote "TestDrive:crypt/ufl16g1kejeblfpcdf7548e43i8hq909bkinusgb0bt9llb2ig7g/gveqi14airsml4bgu7krj116o8" 2025/05/14 03:27:06 DEBUG : one: Need to transfer - File not found at Destination 2025/05/14 03:27:06 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zevijan8roce/dst': Waiting for checks to finish 2025/05/14 03:27:06 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zevijan8roce/dst': Waiting for transfers to finish 2025/05/14 03:27:08 DEBUG : one: md5 = f39f9728ee1697d57fe02fe706c898a3 OK 2025/05/14 03:27:08 INFO : one: Copied (new) 2025/05/14 03:27:08 DEBUG : Waiting for deletions to finish 2025/05/14 03:27:09 DEBUG : one: Sizes differ (src 5 vs dst 3) 2025/05/14 03:27:09 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zevijan8roce/dst': Waiting for checks to finish 2025/05/14 03:27:10 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zevijan8roce/dst': Waiting for transfers to finish 2025/05/14 03:27:11 DEBUG : one: md5 = 96f98d21bd68ff710e8d4a15f24eb5a6 OK 2025/05/14 03:27:11 INFO : one: Copied (replaced existing) 2025/05/14 03:27:11 DEBUG : Waiting for deletions to finish 2025/05/14 03:27:13 DEBUG : dst/one: md5 = d0795ea04b2cd93687c05b22bba7b07a OK 2025/05/14 03:27:15 DEBUG : CompareDest/one: md5 = 2d67f4eee24d8a2d31b2e2cbc88f803d OK 2025/05/14 03:27:15 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zevijan8roce/dst': Waiting for checks to finish 2025/05/14 03:27:15 DEBUG : one: Sizes differ (src 5 vs dst 3) 2025/05/14 03:27:16 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/05/14 03:27:16 DEBUG : one: Destination found in --compare-dest, skipping 2025/05/14 03:27:16 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zevijan8roce/dst': Waiting for transfers to finish 2025/05/14 03:27:16 DEBUG : Waiting for deletions to finish 2025/05/14 03:27:16 INFO : There was nothing to transfer 2025/05/14 03:27:18 DEBUG : CompareDest/two: md5 = 405c7fedb4b3d97c835e5c17a065f330 OK 2025/05/14 03:27:18 DEBUG : one: Sizes differ (src 5 vs dst 3) 2025/05/14 03:27:19 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/05/14 03:27:19 DEBUG : one: Destination found in --compare-dest, skipping 2025/05/14 03:27:19 DEBUG : two: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/05/14 03:27:19 DEBUG : two: Destination found in --compare-dest, skipping 2025/05/14 03:27:19 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zevijan8roce/dst': Waiting for checks to finish 2025/05/14 03:27:19 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zevijan8roce/dst': Waiting for transfers to finish 2025/05/14 03:27:19 DEBUG : Waiting for deletions to finish 2025/05/14 03:27:19 INFO : There was nothing to transfer 2025/05/14 03:27:19 DEBUG : one: Sizes differ (src 5 vs dst 3) 2025/05/14 03:27:19 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/05/14 03:27:19 DEBUG : one: Destination found in --compare-dest, skipping 2025/05/14 03:27:19 DEBUG : two: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/05/14 03:27:19 DEBUG : two: Destination found in --compare-dest, skipping 2025/05/14 03:27:19 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zevijan8roce/dst': Waiting for checks to finish 2025/05/14 03:27:19 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zevijan8roce/dst': Waiting for transfers to finish 2025/05/14 03:27:19 DEBUG : Waiting for deletions to finish 2025/05/14 03:27:19 INFO : There was nothing to transfer sync_test.go:2175: No hash on uploaded file so skipping compare timestamp test 2025/05/14 03:27:21 DEBUG : one: Sizes differ (src 5 vs dst 3) 2025/05/14 03:27:21 DEBUG : two: Sizes differ (src 5 vs dst 3) 2025/05/14 03:27:21 DEBUG : two: Need to transfer - File not found at Destination 2025/05/14 03:27:21 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zevijan8roce/dst': Waiting for checks to finish 2025/05/14 03:27:21 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/05/14 03:27:21 DEBUG : one: Destination found in --compare-dest, skipping 2025/05/14 03:27:21 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zevijan8roce/dst': Waiting for transfers to finish 2025/05/14 03:27:22 DEBUG : two: md5 = f6baaa513d5ad1e9e4f08cd940f04e1e OK 2025/05/14 03:27:22 INFO : two: Copied (new) 2025/05/14 03:27:22 DEBUG : Waiting for deletions to finish 2025/05/14 03:27:25 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k" 2025/05/14 03:27:25 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" 2025/05/14 03:27:26 DEBUG : gveqi14airsml4bgu7krj116o8: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k" 2025/05/14 03:27:26 DEBUG : gveqi14airsml4bgu7krj116o8: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" --- PASS: TestSyncCompareDest (23.86s) === RUN TestSyncMultipleCompareDest run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zevijan8roce'", Local "Local file system at /tmp/rclone2511166019", Modify Window "1ms" 2025/05/14 03:27:28 DEBUG : pre-dest1/1: md5 = a9b911ba05a303ee286a477291fd8280 OK 2025/05/14 03:27:30 DEBUG : pre-dest2/2: md5 = 7b66e503ceeed0ebd6c1b81cdc1a0002 OK 2025/05/14 03:27:31 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-zevijan8roce/dest" 2025/05/14 03:27:31 DEBUG : Creating backend with remote "TestDrive:crypt/ufl16g1kejeblfpcdf7548e43i8hq909bkinusgb0bt9llb2ig7g/rg03c1jvnehrrc617i0lnqjddc" 2025/05/14 03:27:32 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-zevijan8roce/pre-dest1" 2025/05/14 03:27:32 DEBUG : Creating backend with remote "TestDrive:crypt/ufl16g1kejeblfpcdf7548e43i8hq909bkinusgb0bt9llb2ig7g/bbnblvh6k061ssopqrp18kd7gc" 2025/05/14 03:27:33 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-zevijan8roce/pre-dest2" 2025/05/14 03:27:33 DEBUG : Creating backend with remote "TestDrive:crypt/ufl16g1kejeblfpcdf7548e43i8hq909bkinusgb0bt9llb2ig7g/dgicm1h6b5ejvlltm8eeif0bnk" 2025/05/14 03:27:34 DEBUG : 1: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/05/14 03:27:34 DEBUG : 1: Destination found in --compare-dest, skipping 2025/05/14 03:27:35 DEBUG : 2: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/05/14 03:27:35 DEBUG : 2: Destination found in --compare-dest, skipping 2025/05/14 03:27:35 DEBUG : 3: Need to transfer - File not found at Destination 2025/05/14 03:27:35 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zevijan8roce/dest': Waiting for checks to finish 2025/05/14 03:27:35 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zevijan8roce/dest': Waiting for transfers to finish 2025/05/14 03:27:37 DEBUG : 3: md5 = 6218a57b42a1519983d69be722ddb942 OK 2025/05/14 03:27:37 INFO : 3: Copied (new) 2025/05/14 03:27:37 DEBUG : Waiting for deletions to finish 2025/05/14 03:27:40 DEBUG : dgicm1h6b5ejvlltm8eeif0bnk: Rmdir: contains trashed file: "1ghu8geql9vrl726n32nrf65bc" 2025/05/14 03:27:41 DEBUG : bbnblvh6k061ssopqrp18kd7gc: Rmdir: contains trashed file: "skbfko3oil7es0lj68ob574sro" 2025/05/14 03:27:42 DEBUG : rg03c1jvnehrrc617i0lnqjddc: Rmdir: contains trashed file: "g072p7hmjchlnj0gibe64c1epg" --- PASS: TestSyncMultipleCompareDest (15.72s) === RUN TestSyncCopyDest run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zevijan8roce'", Local "Local file system at /tmp/rclone2511166019", Modify Window "1ms" 2025/05/14 03:27:42 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-zevijan8roce/dst" 2025/05/14 03:27:42 DEBUG : Creating backend with remote "TestDrive:crypt/ufl16g1kejeblfpcdf7548e43i8hq909bkinusgb0bt9llb2ig7g/31u3jie661vd5p8j7rtc3hgbh0" 2025/05/14 03:27:44 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-zevijan8roce/CopyDest" 2025/05/14 03:27:44 DEBUG : Creating backend with remote "TestDrive:crypt/ufl16g1kejeblfpcdf7548e43i8hq909bkinusgb0bt9llb2ig7g/d09o6po3f7bm6ce32vdgs8h9ls" 2025/05/14 03:27:46 DEBUG : one: Need to transfer - File not found at Destination 2025/05/14 03:27:46 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zevijan8roce/dst': Waiting for checks to finish 2025/05/14 03:27:46 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zevijan8roce/dst': Waiting for transfers to finish 2025/05/14 03:27:48 DEBUG : one: md5 = 97078593fd72c6387f44b1e959a67b41 OK 2025/05/14 03:27:48 INFO : one: Copied (new) 2025/05/14 03:27:48 DEBUG : Waiting for deletions to finish 2025/05/14 03:27:49 DEBUG : one: Sizes differ (src 5 vs dst 3) 2025/05/14 03:27:49 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zevijan8roce/dst': Waiting for checks to finish 2025/05/14 03:27:49 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zevijan8roce/dst': Waiting for transfers to finish 2025/05/14 03:27:50 DEBUG : one: md5 = f587f0d6374f832fa2bc67d6af5a69c4 OK 2025/05/14 03:27:50 INFO : one: Copied (replaced existing) 2025/05/14 03:27:50 DEBUG : Waiting for deletions to finish 2025/05/14 03:27:52 DEBUG : dst/one: md5 = 389826512a9556104b9e959bf2bfea68 OK 2025/05/14 03:27:55 DEBUG : CopyDest/one: md5 = eeb534dfc8bfad1366f1878c904c6670 OK 2025/05/14 03:27:56 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-zevijan8roce/BackupDir" 2025/05/14 03:27:56 DEBUG : Creating backend with remote "TestDrive:crypt/ufl16g1kejeblfpcdf7548e43i8hq909bkinusgb0bt9llb2ig7g/s6dbk3lfi7c9kfvo6j7bla9m0g" 2025/05/14 03:27:58 DEBUG : one: Sizes differ (src 5 vs dst 3) 2025/05/14 03:27:58 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zevijan8roce/dst': Waiting for checks to finish 2025/05/14 03:27:58 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/05/14 03:27:58 DEBUG : one: Sizes differ (src 5 vs dst 3) 2025/05/14 03:28:00 INFO : one: Moved (server-side) 2025/05/14 03:28:01 INFO : one: Copied (server-side copy) 2025/05/14 03:28:01 DEBUG : one: Destination found in --copy-dest, using server-side copy 2025/05/14 03:28:01 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zevijan8roce/dst': Waiting for transfers to finish 2025/05/14 03:28:01 DEBUG : Waiting for deletions to finish 2025/05/14 03:28:03 DEBUG : CopyDest/two: md5 = 6754ff48e70db560040145c3573d3232 OK 2025/05/14 03:28:03 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/05/14 03:28:03 DEBUG : one: Unchanged skipping 2025/05/14 03:28:04 DEBUG : two: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/05/14 03:28:05 INFO : two: Copied (server-side copy) 2025/05/14 03:28:05 DEBUG : two: Destination found in --copy-dest, using server-side copy 2025/05/14 03:28:05 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zevijan8roce/dst': Waiting for checks to finish 2025/05/14 03:28:05 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zevijan8roce/dst': Waiting for transfers to finish 2025/05/14 03:28:05 DEBUG : Waiting for deletions to finish 2025/05/14 03:28:06 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/05/14 03:28:06 DEBUG : one: Unchanged skipping 2025/05/14 03:28:06 DEBUG : two: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/05/14 03:28:06 DEBUG : two: Unchanged skipping 2025/05/14 03:28:06 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zevijan8roce/dst': Waiting for checks to finish 2025/05/14 03:28:06 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zevijan8roce/dst': Waiting for transfers to finish 2025/05/14 03:28:06 DEBUG : Waiting for deletions to finish 2025/05/14 03:28:06 INFO : There was nothing to transfer 2025/05/14 03:28:07 DEBUG : CopyDest/three: md5 = 6aebc83a0ecfee7e14336513f1491790 OK 2025/05/14 03:28:08 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/05/14 03:28:08 DEBUG : one: Unchanged skipping 2025/05/14 03:28:08 DEBUG : three: Sizes differ (src 7 vs dst 5) 2025/05/14 03:28:08 DEBUG : three: Destination not found in --copy-dest 2025/05/14 03:28:08 DEBUG : three: Need to transfer - File not found at Destination 2025/05/14 03:28:08 DEBUG : two: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/05/14 03:28:08 DEBUG : two: Unchanged skipping 2025/05/14 03:28:08 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zevijan8roce/dst': Waiting for checks to finish 2025/05/14 03:28:08 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zevijan8roce/dst': Waiting for transfers to finish 2025/05/14 03:28:10 DEBUG : three: md5 = c18fa9fccede3c46b8029004325d634c OK 2025/05/14 03:28:10 INFO : three: Copied (new) 2025/05/14 03:28:10 DEBUG : Waiting for deletions to finish 2025/05/14 03:28:14 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "b6jdmn2b1adrhc8vikh7edr9os" 2025/05/14 03:28:14 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" 2025/05/14 03:28:14 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k" 2025/05/14 03:28:15 DEBUG : d09o6po3f7bm6ce32vdgs8h9ls: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" 2025/05/14 03:28:15 DEBUG : d09o6po3f7bm6ce32vdgs8h9ls: Rmdir: contains trashed file: "b6jdmn2b1adrhc8vikh7edr9os" 2025/05/14 03:28:15 DEBUG : d09o6po3f7bm6ce32vdgs8h9ls: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k" 2025/05/14 03:28:16 DEBUG : s6dbk3lfi7c9kfvo6j7bla9m0g: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" --- PASS: TestSyncCopyDest (34.02s) === RUN TestSyncBackupDir run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zevijan8roce'", Local "Local file system at /tmp/rclone2511166019", Modify Window "1ms" 2025/05/14 03:28:19 DEBUG : dst/one: md5 = 52cae875d799b854a972e40c37c1b2fb OK 2025/05/14 03:28:20 DEBUG : dst/two: md5 = d23cd9b80ee35ac7d69e8a85a7947c97 OK 2025/05/14 03:28:21 DEBUG : dst/three.txt: md5 = 949c6c5fbe0da9b167d2d8bc70588652 OK 2025/05/14 03:28:22 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-zevijan8roce/dst" 2025/05/14 03:28:22 DEBUG : Config file has changed externally - reloading 2025/05/14 03:28:22 DEBUG : Creating backend with remote "TestDrive:crypt/ufl16g1kejeblfpcdf7548e43i8hq909bkinusgb0bt9llb2ig7g/31u3jie661vd5p8j7rtc3hgbh0" 2025/05/14 03:28:23 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-zevijan8roce/backup" 2025/05/14 03:28:23 DEBUG : Creating backend with remote "TestDrive:crypt/ufl16g1kejeblfpcdf7548e43i8hq909bkinusgb0bt9llb2ig7g/1nrff024r7pq65ecp72fc28jb0" 2025/05/14 03:28:24 DEBUG : one: Sizes differ (src 4 vs dst 3) 2025/05/14 03:28:24 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/05/14 03:28:24 DEBUG : two: Unchanged skipping 2025/05/14 03:28:24 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zevijan8roce/dst': Waiting for checks to finish 2025/05/14 03:28:26 INFO : one: Moved (server-side) 2025/05/14 03:28:26 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zevijan8roce/dst': Waiting for transfers to finish 2025/05/14 03:28:27 DEBUG : one: md5 = 760c244645b23a57c62d359c24db8b86 OK 2025/05/14 03:28:27 INFO : one: Copied (new) 2025/05/14 03:28:27 DEBUG : Waiting for deletions to finish 2025/05/14 03:28:28 INFO : three.txt: Moved (server-side) 2025/05/14 03:28:28 INFO : three.txt: Moved into backup dir 2025/05/14 03:28:30 DEBUG : dst/three.txt: md5 = 91a697671147edd1629ed6326d42416f OK 2025/05/14 03:28:31 DEBUG : one: Sizes differ (src 5 vs dst 4) 2025/05/14 03:28:31 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/05/14 03:28:31 DEBUG : two: Unchanged skipping 2025/05/14 03:28:31 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zevijan8roce/dst': Waiting for checks to finish 2025/05/14 03:28:31 INFO : one: Deleted 2025/05/14 03:28:32 INFO : one: Moved (server-side) 2025/05/14 03:28:32 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zevijan8roce/dst': Waiting for transfers to finish 2025/05/14 03:28:33 DEBUG : one: md5 = af6d4b22523396f39d024c8ee7adddf1 OK 2025/05/14 03:28:33 INFO : one: Copied (new) 2025/05/14 03:28:33 DEBUG : Waiting for deletions to finish 2025/05/14 03:28:34 INFO : three.txt: Deleted 2025/05/14 03:28:35 INFO : three.txt: Moved (server-side) 2025/05/14 03:28:35 INFO : three.txt: Moved into backup dir 2025/05/14 03:28:38 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" 2025/05/14 03:28:38 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k" 2025/05/14 03:28:38 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "tr2hj63d80ftlmvm6a952snjcc" 2025/05/14 03:28:38 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" 2025/05/14 03:28:38 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "tr2hj63d80ftlmvm6a952snjcc" 2025/05/14 03:28:38 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" --- PASS: TestSyncBackupDir (22.65s) === RUN TestSyncBackupDirWithSuffix run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zevijan8roce'", Local "Local file system at /tmp/rclone2511166019", Modify Window "1ms" 2025/05/14 03:28:41 DEBUG : dst/one: md5 = 9f2037f1cf6bda583e446a997c332a3c OK 2025/05/14 03:28:42 DEBUG : dst/two: md5 = 934a447018a5395896e84ba3422545dc OK 2025/05/14 03:28:43 DEBUG : dst/three.txt: md5 = 42ee9a8f2721edb189b0b704eef55717 OK 2025/05/14 03:28:44 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-zevijan8roce/dst" 2025/05/14 03:28:44 DEBUG : Creating backend with remote "TestDrive:crypt/ufl16g1kejeblfpcdf7548e43i8hq909bkinusgb0bt9llb2ig7g/31u3jie661vd5p8j7rtc3hgbh0" 2025/05/14 03:28:45 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-zevijan8roce/backup" 2025/05/14 03:28:45 DEBUG : Creating backend with remote "TestDrive:crypt/ufl16g1kejeblfpcdf7548e43i8hq909bkinusgb0bt9llb2ig7g/1nrff024r7pq65ecp72fc28jb0" 2025/05/14 03:28:47 DEBUG : one: Sizes differ (src 4 vs dst 3) 2025/05/14 03:28:47 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/05/14 03:28:47 DEBUG : two: Unchanged skipping 2025/05/14 03:28:47 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zevijan8roce/dst': Waiting for checks to finish 2025/05/14 03:28:48 INFO : one: Moved (server-side) to: one.bak 2025/05/14 03:28:48 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zevijan8roce/dst': Waiting for transfers to finish 2025/05/14 03:28:50 DEBUG : one: md5 = 4ccb00316381e2ec7e77e1c7cc9d8d5d OK 2025/05/14 03:28:50 INFO : one: Copied (new) 2025/05/14 03:28:50 DEBUG : Waiting for deletions to finish 2025/05/14 03:28:50 INFO : three.txt: Moved (server-side) to: three.txt.bak 2025/05/14 03:28:50 INFO : three.txt: Moved into backup dir 2025/05/14 03:28:52 DEBUG : dst/three.txt: md5 = eea793e147bbd16815d42159c16ddc22 OK 2025/05/14 03:28:53 DEBUG : one: Sizes differ (src 5 vs dst 4) 2025/05/14 03:28:53 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/05/14 03:28:53 DEBUG : two: Unchanged skipping 2025/05/14 03:28:53 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zevijan8roce/dst': Waiting for checks to finish 2025/05/14 03:28:54 INFO : one.bak: Deleted 2025/05/14 03:28:54 INFO : one: Moved (server-side) to: one.bak 2025/05/14 03:28:54 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zevijan8roce/dst': Waiting for transfers to finish 2025/05/14 03:28:55 DEBUG : one: md5 = 4cfa2799b60dd7b88cc62f87425e9369 OK 2025/05/14 03:28:55 INFO : one: Copied (new) 2025/05/14 03:28:55 DEBUG : Waiting for deletions to finish 2025/05/14 03:28:56 INFO : three.txt.bak: Deleted 2025/05/14 03:28:57 INFO : three.txt: Moved (server-side) to: three.txt.bak 2025/05/14 03:28:57 INFO : three.txt: Moved into backup dir 2025/05/14 03:29:00 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" 2025/05/14 03:29:00 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k" 2025/05/14 03:29:01 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "sk91qgsqfn0r271r2ehsaoc20c" 2025/05/14 03:29:01 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "qltcak2uaegtmcoa8vijdppbp8" 2025/05/14 03:29:01 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "qltcak2uaegtmcoa8vijdppbp8" 2025/05/14 03:29:01 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "sk91qgsqfn0r271r2ehsaoc20c" --- PASS: TestSyncBackupDirWithSuffix (22.38s) === RUN TestSyncBackupDirWithSuffixKeepExtension run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zevijan8roce'", Local "Local file system at /tmp/rclone2511166019", Modify Window "1ms" 2025/05/14 03:29:03 DEBUG : dst/one: md5 = ee607fc7aabce20b35fd18ab7334afa1 OK 2025/05/14 03:29:05 DEBUG : dst/two: md5 = aaa8c0d6a771f54167bce119db2f6751 OK 2025/05/14 03:29:06 DEBUG : dst/three.txt: md5 = 8b65f597cd3b33575f3758202c6b334c OK 2025/05/14 03:29:07 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-zevijan8roce/dst" 2025/05/14 03:29:07 DEBUG : Creating backend with remote "TestDrive:crypt/ufl16g1kejeblfpcdf7548e43i8hq909bkinusgb0bt9llb2ig7g/31u3jie661vd5p8j7rtc3hgbh0" 2025/05/14 03:29:07 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-zevijan8roce/backup" 2025/05/14 03:29:08 DEBUG : Creating backend with remote "TestDrive:crypt/ufl16g1kejeblfpcdf7548e43i8hq909bkinusgb0bt9llb2ig7g/1nrff024r7pq65ecp72fc28jb0" 2025/05/14 03:29:09 DEBUG : one: Sizes differ (src 4 vs dst 3) 2025/05/14 03:29:09 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zevijan8roce/dst': Waiting for checks to finish 2025/05/14 03:29:09 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/05/14 03:29:09 DEBUG : two: Unchanged skipping 2025/05/14 03:29:11 INFO : one: Moved (server-side) to: one-2019-01-01 2025/05/14 03:29:11 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zevijan8roce/dst': Waiting for transfers to finish 2025/05/14 03:29:12 DEBUG : one: md5 = 804d3564eb1d7fd40137bdbe8a88b208 OK 2025/05/14 03:29:12 INFO : one: Copied (new) 2025/05/14 03:29:12 DEBUG : Waiting for deletions to finish 2025/05/14 03:29:13 INFO : three.txt: Moved (server-side) to: three-2019-01-01.txt 2025/05/14 03:29:13 INFO : three.txt: Moved into backup dir 2025/05/14 03:29:15 DEBUG : dst/three.txt: md5 = d512b04691a55bfd34ee1317f2011ca5 OK 2025/05/14 03:29:15 DEBUG : one: Sizes differ (src 5 vs dst 4) 2025/05/14 03:29:15 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/05/14 03:29:15 DEBUG : two: Unchanged skipping 2025/05/14 03:29:15 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zevijan8roce/dst': Waiting for checks to finish 2025/05/14 03:29:16 INFO : one-2019-01-01: Deleted 2025/05/14 03:29:17 INFO : one: Moved (server-side) to: one-2019-01-01 2025/05/14 03:29:17 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zevijan8roce/dst': Waiting for transfers to finish 2025/05/14 03:29:18 DEBUG : one: md5 = 86f0e2274e35e7f8b4730aeb3cba4d7b OK 2025/05/14 03:29:18 INFO : one: Copied (new) 2025/05/14 03:29:18 DEBUG : Waiting for deletions to finish 2025/05/14 03:29:19 INFO : three-2019-01-01.txt: Deleted 2025/05/14 03:29:20 INFO : three.txt: Moved (server-side) to: three-2019-01-01.txt 2025/05/14 03:29:20 INFO : three.txt: Moved into backup dir 2025/05/14 03:29:23 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" 2025/05/14 03:29:23 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k" 2025/05/14 03:29:23 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "jcjl1bv3ep0v8kt35lqql1co90" 2025/05/14 03:29:23 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "qtq2f6qq4lgpsmj88vb7147qje3prudmtfdtr2342fth58vo9a50" 2025/05/14 03:29:23 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "qtq2f6qq4lgpsmj88vb7147qje3prudmtfdtr2342fth58vo9a50" 2025/05/14 03:29:23 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "jcjl1bv3ep0v8kt35lqql1co90" --- PASS: TestSyncBackupDirWithSuffixKeepExtension (22.75s) === RUN TestSyncBackupDirSuffixOnly run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zevijan8roce'", Local "Local file system at /tmp/rclone2511166019", Modify Window "1ms" 2025/05/14 03:29:26 DEBUG : dst/one: md5 = 2026f870d4d603215f78e11be92feb1a OK 2025/05/14 03:29:27 DEBUG : dst/two: md5 = 40ac883e254dbc0088b84f1e4081ede1 OK 2025/05/14 03:29:29 DEBUG : dst/three.txt: md5 = d5aa0664623f4e689c9e9b2bb9f9f541 OK 2025/05/14 03:29:30 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-zevijan8roce/dst" 2025/05/14 03:29:30 DEBUG : Creating backend with remote "TestDrive:crypt/ufl16g1kejeblfpcdf7548e43i8hq909bkinusgb0bt9llb2ig7g/31u3jie661vd5p8j7rtc3hgbh0" 2025/05/14 03:29:31 DEBUG : one: Sizes differ (src 4 vs dst 3) 2025/05/14 03:29:31 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zevijan8roce/dst': Waiting for checks to finish 2025/05/14 03:29:31 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/05/14 03:29:31 DEBUG : two: Unchanged skipping 2025/05/14 03:29:31 INFO : one: Moved (server-side) to: one.bak 2025/05/14 03:29:31 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zevijan8roce/dst': Waiting for transfers to finish 2025/05/14 03:29:33 DEBUG : one: md5 = c4ceaf524d7cbaa8147e8bda8dedef1f OK 2025/05/14 03:29:33 INFO : one: Copied (new) 2025/05/14 03:29:33 DEBUG : Waiting for deletions to finish 2025/05/14 03:29:33 INFO : three.txt: Moved (server-side) to: three.txt.bak 2025/05/14 03:29:33 INFO : three.txt: Moved into backup dir 2025/05/14 03:29:35 DEBUG : dst/three.txt: md5 = b144dba614aac290c8c13a34461c682e OK 2025/05/14 03:29:36 DEBUG : one.bak: Excluded (Path Filter) 2025/05/14 03:29:36 DEBUG : three.txt.bak: Excluded (Path Filter) 2025/05/14 03:29:36 DEBUG : one: Sizes differ (src 5 vs dst 4) 2025/05/14 03:29:36 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/05/14 03:29:36 DEBUG : two: Unchanged skipping 2025/05/14 03:29:36 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zevijan8roce/dst': Waiting for checks to finish 2025/05/14 03:29:37 INFO : one.bak: Deleted 2025/05/14 03:29:37 INFO : one: Moved (server-side) to: one.bak 2025/05/14 03:29:37 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zevijan8roce/dst': Waiting for transfers to finish 2025/05/14 03:29:39 DEBUG : one: md5 = ca387806e4c73e3ee5b88edb06aaee3b OK 2025/05/14 03:29:39 INFO : one: Copied (new) 2025/05/14 03:29:39 DEBUG : Waiting for deletions to finish 2025/05/14 03:29:39 INFO : three.txt.bak: Deleted 2025/05/14 03:29:40 INFO : three.txt: Moved (server-side) to: three.txt.bak 2025/05/14 03:29:40 INFO : three.txt: Moved into backup dir 2025/05/14 03:29:43 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" 2025/05/14 03:29:43 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "sk91qgsqfn0r271r2ehsaoc20c" 2025/05/14 03:29:43 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "qltcak2uaegtmcoa8vijdppbp8" 2025/05/14 03:29:43 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "qltcak2uaegtmcoa8vijdppbp8" 2025/05/14 03:29:43 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "sk91qgsqfn0r271r2ehsaoc20c" 2025/05/14 03:29:43 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k" --- PASS: TestSyncBackupDirSuffixOnly (19.33s) === RUN TestSyncSuffix run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zevijan8roce'", Local "Local file system at /tmp/rclone2511166019", Modify Window "1ms" 2025/05/14 03:29:45 DEBUG : dst/one: md5 = 5c1e8a8ea7079449237085f934731d89 OK 2025/05/14 03:29:47 DEBUG : dst/two: md5 = b6c90b8537234475fd7e486d87bb1d76 OK 2025/05/14 03:29:48 DEBUG : dst/three.txt: md5 = bff7e13d7f11adb0bcdb768e6ae0e3dd OK 2025/05/14 03:29:49 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-zevijan8roce/dst" 2025/05/14 03:29:49 DEBUG : Creating backend with remote "TestDrive:crypt/ufl16g1kejeblfpcdf7548e43i8hq909bkinusgb0bt9llb2ig7g/31u3jie661vd5p8j7rtc3hgbh0" 2025/05/14 03:29:50 DEBUG : one: Sizes differ (src 4 vs dst 3) 2025/05/14 03:29:50 INFO : one: Moved (server-side) to: one.bak 2025/05/14 03:29:52 DEBUG : one: md5 = 978eace044a937a3904b96fe8f3c7987 OK 2025/05/14 03:29:52 INFO : one: Copied (new) 2025/05/14 03:29:52 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/05/14 03:29:52 DEBUG : two: Unchanged skipping 2025/05/14 03:29:52 DEBUG : three.txt: Sizes differ (src 6 vs dst 5) 2025/05/14 03:29:53 INFO : three.txt: Moved (server-side) to: three.txt.bak 2025/05/14 03:29:54 DEBUG : three.txt: md5 = e0a58fa7ff19e1cc4912c94219aea239 OK 2025/05/14 03:29:54 INFO : three.txt: Copied (new) 2025/05/14 03:29:55 DEBUG : one: Sizes differ (src 5 vs dst 4) 2025/05/14 03:29:56 INFO : one.bak: Deleted 2025/05/14 03:29:57 INFO : one: Moved (server-side) to: one.bak 2025/05/14 03:29:58 DEBUG : one: md5 = 940f9d1d3c7b163b05ddd069adb00ee0 OK 2025/05/14 03:29:58 INFO : one: Copied (new) 2025/05/14 03:29:58 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/05/14 03:29:58 DEBUG : two: Unchanged skipping 2025/05/14 03:29:58 DEBUG : three.txt: Sizes differ (src 19 vs dst 6) 2025/05/14 03:29:59 INFO : three.txt.bak: Deleted 2025/05/14 03:29:59 INFO : three.txt: Moved (server-side) to: three.txt.bak 2025/05/14 03:30:01 DEBUG : three.txt: md5 = 499cc4c22f6d09d2c09c1f39737fd224 OK 2025/05/14 03:30:01 INFO : three.txt: Copied (new) 2025/05/14 03:30:05 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" 2025/05/14 03:30:05 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "tr2hj63d80ftlmvm6a952snjcc" 2025/05/14 03:30:05 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "qltcak2uaegtmcoa8vijdppbp8" 2025/05/14 03:30:05 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "sk91qgsqfn0r271r2ehsaoc20c" 2025/05/14 03:30:05 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k" 2025/05/14 03:30:05 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "qltcak2uaegtmcoa8vijdppbp8" 2025/05/14 03:30:05 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "sk91qgsqfn0r271r2ehsaoc20c" --- PASS: TestSyncSuffix (21.91s) === RUN TestSyncSuffixKeepExtension run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zevijan8roce'", Local "Local file system at /tmp/rclone2511166019", Modify Window "1ms" 2025/05/14 03:30:07 DEBUG : dst/one: md5 = 79d399d1e8064427a04a4e459ee0f33e OK 2025/05/14 03:30:09 DEBUG : dst/two: md5 = e41ad7517a353cf15dee20cb77c8a3a9 OK 2025/05/14 03:30:10 DEBUG : dst/three.txt: md5 = 2bd563aad4ff308adc6ff9be1891c6f5 OK 2025/05/14 03:30:10 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-zevijan8roce/dst" 2025/05/14 03:30:11 DEBUG : Creating backend with remote "TestDrive:crypt/ufl16g1kejeblfpcdf7548e43i8hq909bkinusgb0bt9llb2ig7g/31u3jie661vd5p8j7rtc3hgbh0" 2025/05/14 03:30:12 DEBUG : one: Sizes differ (src 4 vs dst 3) 2025/05/14 03:30:12 INFO : one: Moved (server-side) to: one-2019-01-01 2025/05/14 03:30:14 DEBUG : one: md5 = a61eae13320178f06991a5a6b1442cf2 OK 2025/05/14 03:30:14 INFO : one: Copied (new) 2025/05/14 03:30:14 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/05/14 03:30:14 DEBUG : two: Unchanged skipping 2025/05/14 03:30:14 DEBUG : three.txt: Sizes differ (src 6 vs dst 5) 2025/05/14 03:30:15 INFO : three.txt: Moved (server-side) to: three-2019-01-01.txt 2025/05/14 03:30:17 DEBUG : three.txt: md5 = 9b002dee7186c0a4736aeb8ad0ca5064 OK 2025/05/14 03:30:17 INFO : three.txt: Copied (new) 2025/05/14 03:30:18 DEBUG : one: Sizes differ (src 5 vs dst 4) 2025/05/14 03:30:18 INFO : one-2019-01-01: Deleted 2025/05/14 03:30:19 INFO : one: Moved (server-side) to: one-2019-01-01 2025/05/14 03:30:20 DEBUG : one: md5 = 9a5159c8e813fc458880f8836ee3fb07 OK 2025/05/14 03:30:20 INFO : one: Copied (new) 2025/05/14 03:30:21 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/05/14 03:30:21 DEBUG : two: Unchanged skipping 2025/05/14 03:30:21 DEBUG : three.txt: Sizes differ (src 19 vs dst 6) 2025/05/14 03:30:22 INFO : three-2019-01-01.txt: Deleted 2025/05/14 03:30:22 INFO : three.txt: Moved (server-side) to: three-2019-01-01.txt 2025/05/14 03:30:23 DEBUG : three.txt: md5 = 1f4a1cf5be6fbc5195b4fb5b7c679e51 OK 2025/05/14 03:30:23 INFO : three.txt: Copied (new) 2025/05/14 03:30:27 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "tr2hj63d80ftlmvm6a952snjcc" 2025/05/14 03:30:27 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" 2025/05/14 03:30:27 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "jcjl1bv3ep0v8kt35lqql1co90" 2025/05/14 03:30:27 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k" 2025/05/14 03:30:27 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "jcjl1bv3ep0v8kt35lqql1co90" 2025/05/14 03:30:27 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "qtq2f6qq4lgpsmj88vb7147qje3prudmtfdtr2342fth58vo9a50" 2025/05/14 03:30:27 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "qtq2f6qq4lgpsmj88vb7147qje3prudmtfdtr2342fth58vo9a50" --- PASS: TestSyncSuffixKeepExtension (22.34s) === RUN TestSyncUTFNorm run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zevijan8roce'", Local "Local file system at /tmp/rclone2511166019", Modify Window "1ms" 2025/05/14 03:30:29 DEBUG : Testêé: md5 = 2e2f53706adeeed31217e80bf58af904 OK 2025/05/14 03:30:29 DEBUG : Testêé: Sizes differ (src 14 vs dst 18) 2025/05/14 03:30:29 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zevijan8roce': Waiting for checks to finish 2025/05/14 03:30:29 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zevijan8roce': Waiting for transfers to finish 2025/05/14 03:30:31 DEBUG : Testêé: md5 = a8a7b8e26812d17d325e5a2ff10e8db3 OK 2025/05/14 03:30:31 INFO : Testêé: Copied (replaced existing) to: Testêé 2025/05/14 03:30:31 DEBUG : Waiting for deletions to finish --- PASS: TestSyncUTFNorm (4.10s) === RUN TestSyncImmutable run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zevijan8roce'", Local "Local file system at /tmp/rclone2511166019", Modify Window "1ms" 2025/05/14 03:30:32 DEBUG : existing: Need to transfer - File not found at Destination 2025/05/14 03:30:32 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zevijan8roce': Waiting for checks to finish 2025/05/14 03:30:32 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zevijan8roce': Waiting for transfers to finish 2025/05/14 03:30:34 DEBUG : existing: md5 = d7a70373089e904a4de18a9b65e9073a OK 2025/05/14 03:30:34 INFO : existing: Copied (new) 2025/05/14 03:30:34 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zevijan8roce'", Local "Local file system at /tmp/rclone2511166019", Modify Window "1ms" 2025/05/14 03:30:34 DEBUG : existing: Sizes differ (src 8 vs dst 6) 2025/05/14 03:30:34 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zevijan8roce': Waiting for checks to finish 2025/05/14 03:30:34 ERROR : existing: Source and destination exist but do not match: immutable file modified 2025/05/14 03:30:34 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zevijan8roce': Waiting for transfers to finish 2025/05/14 03:30:34 ERROR : Encrypted drive 'TestCryptDrive:rclone-test-zevijan8roce': not deleting files as there were IO errors 2025/05/14 03:30:34 ERROR : Encrypted drive 'TestCryptDrive:rclone-test-zevijan8roce': not deleting directories as there were IO errors run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zevijan8roce'", Local "Local file system at /tmp/rclone2511166019", Modify Window "1ms" --- PASS: TestSyncImmutable (4.83s) === RUN TestSyncIgnoreCase run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zevijan8roce'", Local "Local file system at /tmp/rclone2511166019", Modify Window "1ms" 2025/05/14 03:30:38 DEBUG : EXISTING: md5 = 44c728ac4e5975b6c7912f5e73e34641 OK 2025/05/14 03:30:38 DEBUG : existing: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/05/14 03:30:38 DEBUG : existing: Unchanged skipping 2025/05/14 03:30:38 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zevijan8roce': Waiting for checks to finish 2025/05/14 03:30:38 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zevijan8roce': Waiting for transfers to finish 2025/05/14 03:30:38 DEBUG : Waiting for deletions to finish 2025/05/14 03:30:38 INFO : There was nothing to transfer --- PASS: TestSyncIgnoreCase (3.06s) === RUN TestFixCase run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zevijan8roce'", Local "Local file system at /tmp/rclone2511166019", Modify Window "1ms" sync_test.go:2635: Skipping test as local or remote are case-sensitive --- SKIP: TestFixCase (0.47s) === RUN TestMaxTransfer === RUN TestMaxTransfer/Hard run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zevijan8roce'", Local "Local file system at /tmp/rclone2511166019", 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-zevijan8roce'", Local "Local file system at /tmp/rclone2511166019", 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-zevijan8roce'", Local "Local file system at /tmp/rclone2511166019", Modify Window "1ms" sync_test.go:2674: This test only runs on local --- PASS: TestMaxTransfer (1.33s) --- SKIP: TestMaxTransfer/Hard (0.45s) --- SKIP: TestMaxTransfer/Soft (0.44s) --- SKIP: TestMaxTransfer/Cautious (0.43s) === RUN TestSyncConcurrentDelete run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zevijan8roce'", Local "Local file system at /tmp/rclone2511166019", Modify Window "1ms" 2025/05/14 03:30:43 DEBUG : both0: md5 = 47d3b3d18046fb8de1dbd78be9ca1408 OK 2025/05/14 03:30:44 DEBUG : only0: md5 = e6c641ed01491ed08f696d91fc1e3548 OK 2025/05/14 03:30:45 DEBUG : both1: md5 = b08b49d0acde8ce3e7662f516e721392 OK 2025/05/14 03:30:47 DEBUG : only1: md5 = 51431069f92a905ea0c5d26c56df352d OK 2025/05/14 03:30:48 DEBUG : both2: md5 = 3aead3f4cbdbd7e71a07bbeb12e6fdb3 OK 2025/05/14 03:30:49 DEBUG : only2: md5 = b20a7e6350f3147c140d412d58880687 OK 2025/05/14 03:30:51 DEBUG : both3: md5 = 8b3b1ad154e30d78dafb5dcf0d3aff3d OK 2025/05/14 03:30:52 DEBUG : only3: md5 = e30754bd25e67b9a07e12e55ee603801 OK 2025/05/14 03:30:53 DEBUG : both4: md5 = 5f3080cc98c95ee353c962990c26633c OK 2025/05/14 03:30:55 DEBUG : only4: md5 = 488d451d13332dd5683cb5b283cddffd OK 2025/05/14 03:30:56 DEBUG : both5: md5 = 8d78cdca50a23530e8ab037a1c35932b OK 2025/05/14 03:30:57 DEBUG : only5: md5 = c5868cc1bf8ac5ba61629fde27a1a85d OK 2025/05/14 03:30:59 DEBUG : both6: md5 = a627f8a18c5a02de54877f11f966e077 OK 2025/05/14 03:31:00 DEBUG : only6: md5 = 50e1e39ddfec301c86b716c56aa675d7 OK 2025/05/14 03:31:01 DEBUG : both7: md5 = 12470fb9e8f43d54b8d63550adfd6917 OK 2025/05/14 03:31:03 DEBUG : only7: md5 = d3c16fc0cd04c4bed40c0b781d0053d6 OK 2025/05/14 03:31:04 DEBUG : both8: md5 = 8f1a06db68d3339c217b5b63a24579ca OK 2025/05/14 03:31:05 DEBUG : only8: md5 = 2d238d909e9bb96af6262ff630e12ae0 OK 2025/05/14 03:31:07 DEBUG : both9: md5 = c653a8ba6e09a2773ac7473c263bf582 OK 2025/05/14 03:31:09 DEBUG : only9: md5 = 9f90074601083b339f774c90778c4bf5 OK 2025/05/14 03:31:10 DEBUG : both10: md5 = 591d274ad060501dfeb19c582711d819 OK 2025/05/14 03:31:12 DEBUG : only10: md5 = bd561f5d0bfe8114bfbcbf14f447bbd9 OK 2025/05/14 03:31:13 DEBUG : both11: md5 = 4d7cd94413222bf0580404bde5359824 OK 2025/05/14 03:31:14 DEBUG : only11: md5 = 762dc25f623feff30c17d1209e6eb4b4 OK 2025/05/14 03:31:16 DEBUG : both12: md5 = a02bef2e2e3dc4a60278a819c0d83111 OK 2025/05/14 03:31:17 DEBUG : only12: md5 = 988ec537d917016da24b8299b135bb2e OK 2025/05/14 03:31:19 DEBUG : both13: md5 = 1644adeb46f84fbd7da55c106952562b OK 2025/05/14 03:31:20 DEBUG : only13: md5 = 39d5c72da8acd48ab805ede16aa1e67c OK 2025/05/14 03:31:21 DEBUG : both14: md5 = 0c804340831f99bbf58653e3522387e4 OK 2025/05/14 03:31:23 DEBUG : only14: md5 = 3539dfff9b9907954c9dab6e7f2763ea OK 2025/05/14 03:31:24 DEBUG : both15: md5 = c05b1d9dbe9d8f2a3620485d9ce1e212 OK 2025/05/14 03:31:25 DEBUG : only15: md5 = 6b07d292ec64e9845deac5169dc45ef3 OK 2025/05/14 03:31:27 DEBUG : both16: md5 = ff045994b30ab554c385ee0eaa0c5545 OK 2025/05/14 03:31:28 DEBUG : only16: md5 = b29f0612e27b36fbd61552e34b35aeb6 OK 2025/05/14 03:31:29 DEBUG : both17: md5 = 1ef944416011c71a2bc3ead746a7e953 OK 2025/05/14 03:31:31 DEBUG : only17: md5 = a010a26165b9fa5ef4d419849123f95b OK 2025/05/14 03:31:32 DEBUG : both18: md5 = 756aa1c4eae327334e876b5977976bea OK 2025/05/14 03:31:33 DEBUG : only18: md5 = 70cdd08f8add0a871a45171442bad2c8 OK 2025/05/14 03:31:35 DEBUG : both19: md5 = d5e6f436334261dc9136641ab17254ba OK 2025/05/14 03:31:36 DEBUG : only19: md5 = da713d1360acafb6f457c92698b09755 OK 2025/05/14 03:31:36 DEBUG : both0: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/05/14 03:31:36 DEBUG : both10: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/05/14 03:31:36 DEBUG : both11: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/05/14 03:31:36 DEBUG : both1: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/05/14 03:31:36 DEBUG : both10: Unchanged skipping 2025/05/14 03:31:36 DEBUG : both12: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/05/14 03:31:36 DEBUG : both12: Unchanged skipping 2025/05/14 03:31:36 DEBUG : both13: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/05/14 03:31:36 DEBUG : both13: Unchanged skipping 2025/05/14 03:31:36 DEBUG : both14: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/05/14 03:31:36 DEBUG : both14: Unchanged skipping 2025/05/14 03:31:36 DEBUG : both15: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/05/14 03:31:36 DEBUG : both15: Unchanged skipping 2025/05/14 03:31:36 DEBUG : both16: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/05/14 03:31:36 DEBUG : both0: Unchanged skipping 2025/05/14 03:31:36 DEBUG : both17: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/05/14 03:31:36 DEBUG : both11: Unchanged skipping 2025/05/14 03:31:36 DEBUG : both18: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/05/14 03:31:36 DEBUG : both1: Unchanged skipping 2025/05/14 03:31:36 DEBUG : both19: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/05/14 03:31:36 DEBUG : both19: Unchanged skipping 2025/05/14 03:31:36 DEBUG : both2: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/05/14 03:31:36 DEBUG : both2: Unchanged skipping 2025/05/14 03:31:36 DEBUG : both3: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/05/14 03:31:36 DEBUG : both3: Unchanged skipping 2025/05/14 03:31:36 DEBUG : both4: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/05/14 03:31:36 DEBUG : both4: Unchanged skipping 2025/05/14 03:31:36 DEBUG : both5: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/05/14 03:31:36 DEBUG : both5: Unchanged skipping 2025/05/14 03:31:36 DEBUG : both6: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/05/14 03:31:36 DEBUG : both6: Unchanged skipping 2025/05/14 03:31:36 DEBUG : both7: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/05/14 03:31:36 DEBUG : both7: Unchanged skipping 2025/05/14 03:31:36 DEBUG : both8: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/05/14 03:31:36 DEBUG : both8: Unchanged skipping 2025/05/14 03:31:36 DEBUG : both9: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/05/14 03:31:36 DEBUG : both9: Unchanged skipping 2025/05/14 03:31:36 DEBUG : both17: Unchanged skipping 2025/05/14 03:31:36 DEBUG : both18: Unchanged skipping 2025/05/14 03:31:36 DEBUG : both16: Unchanged skipping 2025/05/14 03:31:36 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zevijan8roce': Waiting for checks to finish 2025/05/14 03:31:36 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zevijan8roce': Waiting for transfers to finish 2025/05/14 03:31:36 DEBUG : Waiting for deletions to finish 2025/05/14 03:31:37 INFO : only13: Deleted 2025/05/14 03:31:37 INFO : only12: Deleted 2025/05/14 03:31:37 INFO : only8: Deleted 2025/05/14 03:31:37 INFO : only19: Deleted 2025/05/14 03:31:37 INFO : only16: Deleted 2025/05/14 03:31:37 INFO : only17: Deleted 2025/05/14 03:31:37 INFO : only18: Deleted 2025/05/14 03:31:38 INFO : only2: Deleted 2025/05/14 03:31:38 INFO : only0: Deleted 2025/05/14 03:31:38 INFO : only3: Deleted 2025/05/14 03:31:38 INFO : only11: Deleted 2025/05/14 03:31:38 INFO : only5: Deleted 2025/05/14 03:31:38 INFO : only7: Deleted 2025/05/14 03:31:38 INFO : only14: Deleted 2025/05/14 03:31:38 INFO : only15: Deleted 2025/05/14 03:31:39 INFO : only4: Deleted 2025/05/14 03:31:39 INFO : only6: Deleted 2025/05/14 03:31:39 INFO : only9: Deleted 2025/05/14 03:31:39 INFO : only1: Deleted 2025/05/14 03:31:39 INFO : only10: Deleted 2025/05/14 03:31:39 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zevijan8roce'", Local "Local file system at /tmp/rclone2511166019", Modify Window "1ms" --- PASS: TestSyncConcurrentDelete (67.79s) === RUN TestSyncConcurrentTruncate run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zevijan8roce'", Local "Local file system at /tmp/rclone2511166019", Modify Window "1ms" 2025/05/14 03:31:51 DEBUG : both0: md5 = e7da58d260e47eb3591efc5387b13b13 OK 2025/05/14 03:31:52 DEBUG : only0: md5 = 797fe21a805bbedda59979051fb7746a OK 2025/05/14 03:31:53 DEBUG : both1: md5 = 51bf7f1ce6c0bd5d8cb3a19a81aa9b90 OK 2025/05/14 03:31:55 DEBUG : only1: md5 = 0255c4e3c66fe7ebd33ba9f1aae1fa0b OK 2025/05/14 03:31:56 DEBUG : both2: md5 = e712cd095f80737644dd3ab8fd9b3730 OK 2025/05/14 03:31:57 DEBUG : only2: md5 = 9a626b357146c5febfbbe505238d7ad7 OK 2025/05/14 03:31:59 DEBUG : both3: md5 = 2a2fa228d98fce1810d4ad7326ddd2fc OK 2025/05/14 03:32:00 DEBUG : only3: md5 = 593595fee9455d21c854cb2a084f689a OK 2025/05/14 03:32:01 DEBUG : both4: md5 = fd1532c934badb84b4949b347d6a76ca OK 2025/05/14 03:32:03 DEBUG : only4: md5 = 6aa222f1efe096aa1b81d0166ceae6ad OK 2025/05/14 03:32:04 DEBUG : both5: md5 = 44704a689be0ad6227631f7f3137399a OK 2025/05/14 03:32:05 DEBUG : only5: md5 = e864906f7f90ef0115ab6dcbb2b72746 OK 2025/05/14 03:32:06 DEBUG : both6: md5 = 4cdf7a3685a6ea720b22922a16933370 OK 2025/05/14 03:32:08 DEBUG : only6: md5 = c1e67b26ae1a052693ceb32be3ab5352 OK 2025/05/14 03:32:09 DEBUG : both7: md5 = bb104dfd45db1da11a41583a56599cbb OK 2025/05/14 03:32:10 DEBUG : only7: md5 = f22b35191d326c099b145b13351c05f6 OK 2025/05/14 03:32:12 DEBUG : both8: md5 = 02781936eb1550da6050c233ac0b0b75 OK 2025/05/14 03:32:13 DEBUG : only8: md5 = afe4213d867aa58658243affe936b1f2 OK 2025/05/14 03:32:14 DEBUG : both9: md5 = 7b29bfa8290e2bdaa70ab947c75bb770 OK 2025/05/14 03:32:16 DEBUG : only9: md5 = 01f5bc9c00fa1c48282ae682ddc9ba8b OK 2025/05/14 03:32:17 DEBUG : both10: md5 = 48b115f776811a2710a5be632b76f665 OK 2025/05/14 03:32:18 DEBUG : only10: md5 = dabb8e1911f3d2e667f5d9993fbcb466 OK 2025/05/14 03:32:20 DEBUG : both11: md5 = c79e4755936dccb366189b068b16dfea OK 2025/05/14 03:32:21 DEBUG : only11: md5 = dcde71653ce3c8284670f6e915a75d52 OK 2025/05/14 03:32:22 DEBUG : both12: md5 = a50465060c6662c9dfa57a8e459df11c OK 2025/05/14 03:32:24 DEBUG : only12: md5 = fc1ecacd28f7646bad27ec4b12ed8ea5 OK 2025/05/14 03:32:25 DEBUG : both13: md5 = 2a0f76ff7c157f8b82e446fb33a62930 OK 2025/05/14 03:32:26 DEBUG : only13: md5 = a11b95ae87d721e95acb313e5211f3ba OK 2025/05/14 03:32:28 DEBUG : both14: md5 = 8fc4d35a3996e0abb9c8c0deccc3b0f2 OK 2025/05/14 03:32:29 DEBUG : only14: md5 = 3afa94205de335e4520e6ff56a662172 OK 2025/05/14 03:32:30 DEBUG : both15: md5 = f903ce4a361d554b148c7240492b45dd OK 2025/05/14 03:32:32 DEBUG : only15: md5 = d6a921db8084d993abb8a74e239f92e6 OK 2025/05/14 03:32:33 DEBUG : both16: md5 = 362adde10a5cabe39f70bdc62cb9eb81 OK 2025/05/14 03:32:35 DEBUG : only16: md5 = 59ba5e682403abc208bde2af953a219a OK 2025/05/14 03:32:36 DEBUG : both17: md5 = 62d69f16f39b55a7edf1a9f09f921281 OK 2025/05/14 03:32:37 DEBUG : only17: md5 = 8d990bce4d70ef48e1140cc379466a0f OK 2025/05/14 03:32:39 DEBUG : both18: md5 = 7f1330d81b3435dd87187604f00322a5 OK 2025/05/14 03:32:44 DEBUG : only18: md5 = 422fed8ca9f3eabdcf26fc648706ba72 OK 2025/05/14 03:32:47 DEBUG : both19: md5 = 77056bb77855f852dd4a275e11fc02a8 OK 2025/05/14 03:32:49 DEBUG : only19: md5 = 88d205d517b5aecc3ded61f871ff04cf OK 2025/05/14 03:32:49 DEBUG : both0: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/05/14 03:32:49 DEBUG : both1: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/05/14 03:32:49 DEBUG : both10: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/05/14 03:32:49 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zevijan8roce': Waiting for checks to finish 2025/05/14 03:32:49 DEBUG : both11: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/05/14 03:32:49 DEBUG : both0: Unchanged skipping 2025/05/14 03:32:49 DEBUG : both12: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/05/14 03:32:49 DEBUG : both12: Unchanged skipping 2025/05/14 03:32:49 DEBUG : both13: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/05/14 03:32:49 DEBUG : both13: Unchanged skipping 2025/05/14 03:32:49 DEBUG : both14: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/05/14 03:32:49 DEBUG : both14: Unchanged skipping 2025/05/14 03:32:49 DEBUG : both15: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/05/14 03:32:49 DEBUG : both15: Unchanged skipping 2025/05/14 03:32:49 DEBUG : both16: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/05/14 03:32:49 DEBUG : both16: Unchanged skipping 2025/05/14 03:32:49 DEBUG : both17: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/05/14 03:32:49 DEBUG : both17: Unchanged skipping 2025/05/14 03:32:49 DEBUG : both18: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/05/14 03:32:49 DEBUG : both18: Unchanged skipping 2025/05/14 03:32:49 DEBUG : both19: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/05/14 03:32:49 DEBUG : both19: Unchanged skipping 2025/05/14 03:32:49 DEBUG : both2: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/05/14 03:32:49 DEBUG : both2: Unchanged skipping 2025/05/14 03:32:49 DEBUG : both3: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/05/14 03:32:49 DEBUG : both3: Unchanged skipping 2025/05/14 03:32:49 DEBUG : both4: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/05/14 03:32:49 DEBUG : both4: Unchanged skipping 2025/05/14 03:32:49 DEBUG : both5: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/05/14 03:32:49 DEBUG : both5: Unchanged skipping 2025/05/14 03:32:49 DEBUG : both6: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/05/14 03:32:49 DEBUG : both6: Unchanged skipping 2025/05/14 03:32:49 DEBUG : both7: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/05/14 03:32:49 DEBUG : both7: Unchanged skipping 2025/05/14 03:32:49 DEBUG : both8: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/05/14 03:32:49 DEBUG : both8: Unchanged skipping 2025/05/14 03:32:49 DEBUG : both9: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/05/14 03:32:49 DEBUG : both9: Unchanged skipping 2025/05/14 03:32:49 DEBUG : only0: Sizes differ (src 0 vs dst 6) 2025/05/14 03:32:49 DEBUG : only1: Sizes differ (src 0 vs dst 6) 2025/05/14 03:32:49 DEBUG : only10: Sizes differ (src 0 vs dst 6) 2025/05/14 03:32:49 DEBUG : only11: Sizes differ (src 0 vs dst 6) 2025/05/14 03:32:49 DEBUG : only12: Sizes differ (src 0 vs dst 6) 2025/05/14 03:32:49 DEBUG : only13: Sizes differ (src 0 vs dst 6) 2025/05/14 03:32:49 DEBUG : only14: Sizes differ (src 0 vs dst 6) 2025/05/14 03:32:49 DEBUG : only15: Sizes differ (src 0 vs dst 6) 2025/05/14 03:32:49 DEBUG : only16: Sizes differ (src 0 vs dst 6) 2025/05/14 03:32:49 DEBUG : only17: Sizes differ (src 0 vs dst 6) 2025/05/14 03:32:49 DEBUG : only18: Sizes differ (src 0 vs dst 6) 2025/05/14 03:32:49 DEBUG : only19: Sizes differ (src 0 vs dst 6) 2025/05/14 03:32:49 DEBUG : only2: Sizes differ (src 0 vs dst 6) 2025/05/14 03:32:49 DEBUG : only3: Sizes differ (src 0 vs dst 6) 2025/05/14 03:32:49 DEBUG : only4: Sizes differ (src 0 vs dst 6) 2025/05/14 03:32:49 DEBUG : only5: Sizes differ (src 0 vs dst 6) 2025/05/14 03:32:49 DEBUG : only6: Sizes differ (src 0 vs dst 6) 2025/05/14 03:32:49 DEBUG : only7: Sizes differ (src 0 vs dst 6) 2025/05/14 03:32:49 DEBUG : both1: Unchanged skipping 2025/05/14 03:32:49 DEBUG : only8: Sizes differ (src 0 vs dst 6) 2025/05/14 03:32:49 DEBUG : both10: Unchanged skipping 2025/05/14 03:32:49 DEBUG : only9: Sizes differ (src 0 vs dst 6) 2025/05/14 03:32:49 DEBUG : both11: Unchanged skipping 2025/05/14 03:32:49 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zevijan8roce': Waiting for transfers to finish 2025/05/14 03:32:50 DEBUG : only1: md5 = 50cf821238a3e69e525d6b4855552195 OK 2025/05/14 03:32:50 INFO : only1: Copied (replaced existing) 2025/05/14 03:32:50 DEBUG : only11: md5 = 16465eb591833a8b15f47ef36bfe6bc3 OK 2025/05/14 03:32:50 INFO : only11: Copied (replaced existing) 2025/05/14 03:32:50 DEBUG : only10: md5 = bc59379589e2c51eee574b6a651254db OK 2025/05/14 03:32:50 INFO : only10: Copied (replaced existing) 2025/05/14 03:32:50 DEBUG : only0: md5 = 16eedda81974ec16c0909e0c968d90e8 OK 2025/05/14 03:32:50 INFO : only0: Copied (replaced existing) 2025/05/14 03:32:51 DEBUG : only15: md5 = d3cb1b76641f70fac8a28d873f723761 OK 2025/05/14 03:32:51 INFO : only15: Copied (replaced existing) 2025/05/14 03:32:51 DEBUG : only13: md5 = 99f3941dd8733bb28aa1b75452bd7301 OK 2025/05/14 03:32:51 INFO : only13: Copied (replaced existing) 2025/05/14 03:32:51 DEBUG : only12: md5 = 203ad3b332f383719304b7f1fe4e3ac7 OK 2025/05/14 03:32:51 INFO : only12: Copied (replaced existing) 2025/05/14 03:32:52 DEBUG : only14: md5 = 15245ba77f7f2b2c7a2185e7f0f22e00 OK 2025/05/14 03:32:52 INFO : only14: Copied (replaced existing) 2025/05/14 03:32:52 DEBUG : only18: md5 = f2847a36c52b3bd2dc189a54c3de0926 OK 2025/05/14 03:32:52 INFO : only18: Copied (replaced existing) 2025/05/14 03:32:52 DEBUG : only17: md5 = 7cf6b92ea975287af2de9449f44b7f63 OK 2025/05/14 03:32:52 INFO : only17: Copied (replaced existing) 2025/05/14 03:32:52 DEBUG : only16: md5 = 0c23f41cd09077a2c1e34a2ec3dc4906 OK 2025/05/14 03:32:52 INFO : only16: Copied (replaced existing) 2025/05/14 03:32:53 DEBUG : only19: md5 = 07c3d8f05dbe8f2debe9d0c32e098476 OK 2025/05/14 03:32:53 INFO : only19: Copied (replaced existing) 2025/05/14 03:32:53 DEBUG : only2: md5 = 7b04df44f575ac2eb912b8b1186d8c9e OK 2025/05/14 03:32:53 INFO : only2: Copied (replaced existing) 2025/05/14 03:32:53 DEBUG : only3: md5 = 0ce57df51ed0241915d12646c169ee2a OK 2025/05/14 03:32:53 INFO : only3: Copied (replaced existing) 2025/05/14 03:32:54 DEBUG : only4: md5 = 95b5f6437e5089b0322efc9884c002c3 OK 2025/05/14 03:32:54 INFO : only4: Copied (replaced existing) 2025/05/14 03:32:54 DEBUG : only5: md5 = 5af3c8267bba8ec9562fc8796a77a5b5 OK 2025/05/14 03:32:54 INFO : only5: Copied (replaced existing) 2025/05/14 03:32:55 DEBUG : only6: md5 = dc40f98773970f61e00061a941a023c9 OK 2025/05/14 03:32:55 INFO : only6: Copied (replaced existing) 2025/05/14 03:32:55 DEBUG : only7: md5 = 3bd81937dc0c5f93abfd65fe18396908 OK 2025/05/14 03:32:55 INFO : only7: Copied (replaced existing) 2025/05/14 03:32:55 DEBUG : only8: md5 = f1a0b82fcb6b626f75db444591175b99 OK 2025/05/14 03:32:55 INFO : only8: Copied (replaced existing) 2025/05/14 03:32:55 DEBUG : only9: md5 = d022a5a35de7a1623b53a135a1ec14c3 OK 2025/05/14 03:32:55 INFO : only9: Copied (replaced existing) 2025/05/14 03:32:55 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zevijan8roce'", Local "Local file system at /tmp/rclone2511166019", Modify Window "1ms" --- PASS: TestSyncConcurrentTruncate (84.86s) === RUN TestSyncReplaceDirModTime run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zevijan8roce'", Local "Local file system at /tmp/rclone2511166019", Modify Window "1ms" 2025/05/14 03:33:14 DEBUG : empty_dir: Making directory with metadata 2025/05/14 03:33:14 INFO : empty_dir: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2025/05/14 03:33:14 DEBUG : empty_on_remote: Making directory with metadata 2025/05/14 03:33:14 INFO : empty_on_remote: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2025/05/14 03:33:14 DEBUG : empty_on_remote: Making directory with metadata 2025/05/14 03:33:15 INFO : empty_on_remote: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zevijan8roce'", Local "Local file system at /tmp/rclone2511166019", Modify Window "1ms" 2025/05/14 03:33:20 INFO : test_dir1: Set directory modification time (using DirSetModTime) 2025/05/14 03:33:20 INFO : test_dir2: Set directory modification time (using DirSetModTime) 2025/05/14 03:33:20 INFO : test_dir2/sub_dir: Set directory modification time (using DirSetModTime) 2025/05/14 03:33:20 INFO : empty_on_remote: Set directory modification time (using DirSetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zevijan8roce'", Local "Local file system at /tmp/rclone2511166019", Modify Window "1ms" 2025/05/14 03:33:27 DEBUG : heqj02jg0dcqlem7gl0500bvp0/24g2k8bseitblkmqnie1ibl2s8: Rmdir: contains trashed file: "633fmaa0qic3kv3cladnu11pto" 2025/05/14 03:33:27 DEBUG : heqj02jg0dcqlem7gl0500bvp0: Rmdir: contains trashed file: "24g2k8bseitblkmqnie1ibl2s8" 2025/05/14 03:33:28 DEBUG : gq68srrpl0nnf394bgf7dbu9kc: Rmdir: contains trashed file: "d26uovf0miqhd1mu3c9jbseq00" --- PASS: TestSyncReplaceDirModTime (16.05s) === RUN TestSyncReplaceDirModTimeWithEmptyDirs run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zevijan8roce'", Local "Local file system at /tmp/rclone2511166019", Modify Window "1ms" 2025/05/14 03:33:30 DEBUG : empty_dir: Making directory with metadata 2025/05/14 03:33:30 INFO : empty_dir: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2025/05/14 03:33:30 DEBUG : empty_on_remote: Making directory with metadata 2025/05/14 03:33:30 INFO : empty_on_remote: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2025/05/14 03:33:30 DEBUG : empty_on_remote: Making directory with metadata 2025/05/14 03:33:31 INFO : empty_on_remote: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zevijan8roce'", Local "Local file system at /tmp/rclone2511166019", Modify Window "1ms" 2025/05/14 03:33:36 INFO : test_dir1: Set directory modification time (using DirSetModTime) 2025/05/14 03:33:36 INFO : test_dir2: Set directory modification time (using DirSetModTime) 2025/05/14 03:33:36 INFO : test_dir2/sub_dir: Set directory modification time (using DirSetModTime) 2025/05/14 03:33:36 INFO : empty_on_remote: Set directory modification time (using DirSetModTime) 2025/05/14 03:33:36 INFO : empty_dir: Set directory modification time (using DirSetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zevijan8roce'", Local "Local file system at /tmp/rclone2511166019", Modify Window "1ms" 2025/05/14 03:33:43 DEBUG : heqj02jg0dcqlem7gl0500bvp0/24g2k8bseitblkmqnie1ibl2s8: Rmdir: contains trashed file: "633fmaa0qic3kv3cladnu11pto" 2025/05/14 03:33:44 DEBUG : heqj02jg0dcqlem7gl0500bvp0: Rmdir: contains trashed file: "24g2k8bseitblkmqnie1ibl2s8" 2025/05/14 03:33:44 DEBUG : gq68srrpl0nnf394bgf7dbu9kc: Rmdir: contains trashed file: "d26uovf0miqhd1mu3c9jbseq00" --- PASS: TestSyncReplaceDirModTimeWithEmptyDirs (16.93s) === RUN TestNothingToTransferWithEmptyDirs run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zevijan8roce'", Local "Local file system at /tmp/rclone2511166019", Modify Window "1ms" 2025/05/14 03:33:47 INFO : sub dir: Set directory modification time (using DirSetModTime) 2025/05/14 03:33:47 DEBUG : sub dir: Making directory with metadata 2025/05/14 03:33:48 INFO : sub dir: Made directory with metadata (mtime=2011-12-30T12:59:59Z) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zevijan8roce'", Local "Local file system at /tmp/rclone2511166019", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zevijan8roce'", Local "Local file system at /tmp/rclone2511166019", Modify Window "1ms" 2025/05/14 03:34:04 INFO : sub dir2: Set directory modification time (using DirSetModTime) 2025/05/14 03:34:05 INFO : sub dir2: Set directory modification time (using DirSetModTime) 2025/05/14 03:34:05 INFO : sub dirEmpty/sub dirEmpty2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2025/05/14 03:34:05 INFO : sub dirEmpty: Set directory modification time (using DirSetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zevijan8roce'", Local "Local file system at /tmp/rclone2511166019", Modify Window "1ms" 2025/05/14 03:34:18 DEBUG : gcsdkq814sbtppue42dpsbg8ug: Rmdir: contains trashed file: "sjuo65gk5q3r1199jselk9k9o0" 2025/05/14 03:34:19 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/37qp6d1gohacv723ij3brofbu8/i24n0ln37pa2hv8pctddeuh73o: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" 2025/05/14 03:34:20 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/37qp6d1gohacv723ij3brofbu8: Rmdir: contains trashed file: "i24n0ln37pa2hv8pctddeuh73o" 2025/05/14 03:34:20 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "37qp6d1gohacv723ij3brofbu8" 2025/05/14 03:34:21 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak" 2025/05/14 03:34:22 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak" 2025/05/14 03:34:23 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak" 2025/05/14 03:34:23 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak" 2025/05/14 03:34:24 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/4r13oncfa2rsrr82oqhsqv24ns: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" 2025/05/14 03:34:25 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc: Rmdir: contains trashed file: "4r13oncfa2rsrr82oqhsqv24ns" 2025/05/14 03:34:25 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak" 2025/05/14 03:34:25 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestNothingToTransferWithEmptyDirs (40.29s) === RUN TestNothingToTransferWithoutEmptyDirs run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zevijan8roce'", Local "Local file system at /tmp/rclone2511166019", Modify Window "1ms" 2025/05/14 03:34:27 INFO : sub dir: Set directory modification time (using DirSetModTime) 2025/05/14 03:34:27 DEBUG : sub dir: Making directory with metadata 2025/05/14 03:34:28 INFO : sub dir: Made directory with metadata (mtime=2011-12-30T12:59:59Z) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zevijan8roce'", Local "Local file system at /tmp/rclone2511166019", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zevijan8roce'", Local "Local file system at /tmp/rclone2511166019", Modify Window "1ms" 2025/05/14 03:34:49 INFO : sub dir2: Set directory modification time (using DirSetModTime) 2025/05/14 03:34:49 INFO : sub dir2: Set directory modification time (using DirSetModTime) 2025/05/14 03:34:49 INFO : sub dirEmpty/sub dirEmpty2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2025/05/14 03:34:49 INFO : sub dirEmpty: Set directory modification time (using DirSetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-zevijan8roce'", Local "Local file system at /tmp/rclone2511166019", Modify Window "1ms" 2025/05/14 03:35:01 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/37qp6d1gohacv723ij3brofbu8/i24n0ln37pa2hv8pctddeuh73o: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" 2025/05/14 03:35:02 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/37qp6d1gohacv723ij3brofbu8: Rmdir: contains trashed file: "i24n0ln37pa2hv8pctddeuh73o" 2025/05/14 03:35:03 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "37qp6d1gohacv723ij3brofbu8" 2025/05/14 03:35:03 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak" 2025/05/14 03:35:04 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak" 2025/05/14 03:35:05 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak" 2025/05/14 03:35:06 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak" 2025/05/14 03:35:06 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/4r13oncfa2rsrr82oqhsqv24ns: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" 2025/05/14 03:35:07 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc: Rmdir: contains trashed file: "4r13oncfa2rsrr82oqhsqv24ns" 2025/05/14 03:35:07 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak" 2025/05/14 03:35:08 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestNothingToTransferWithoutEmptyDirs (42.34s) PASS 2025/05/14 03:35:10 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zevijan8roce': Purge remote "./sync.test -test.v -test.timeout 1h0m0s -remote TestCryptDrive: -verbose -fast-list" - Finished OK in 15m42.939737166s (try 1/5)