"./sync.test -test.v -test.timeout 1h0m0s -remote TestCryptDrive: -verbose -fast-list" - Starting (try 1/5) 2025/04/30 01:28:12 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-sabikek0yata" 2025/04/30 01:28:12 DEBUG : Using config file from "/home/rclone/.rclone.conf" 2025/04/30 01:28:12 DEBUG : Creating backend with remote "TestDrive:crypt/pil0n1qm7plo2mg2ir1k4f8njnr2gsmbacqrr6opdumvh038dtog" 2025/04/30 01:28:13 DEBUG : Creating backend with remote "/tmp/rclone1466900237" === RUN TestPipe --- PASS: TestPipe (0.00s) === RUN TestPipeConcurrent --- PASS: TestPipeConcurrent (0.05s) === 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-sabikek0yata'", Local "Local file system at /tmp/rclone1466900237", Modify Window "1ms" 2025/04/30 01:28:14 DEBUG : Added delayed dir = "sub dir", newDst= 2025/04/30 01:28:14 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2025/04/30 01:28:14 NOTICE: sub dir/hello world: Skipped copy as --dry-run is set (size 11) 2025/04/30 01:28:14 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-sabikek0yata': Waiting for checks to finish 2025/04/30 01:28:14 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-sabikek0yata': Waiting for transfers to finish 2025/04/30 01:28:14 NOTICE: sub dir: Skipped set directory modification time as --dry-run is set run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-sabikek0yata'", Local "Local file system at /tmp/rclone1466900237", Modify Window "1ms" --- PASS: TestCopyWithDryRun (2.04s) === RUN TestCopy run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-sabikek0yata'", Local "Local file system at /tmp/rclone1466900237", Modify Window "1ms" 2025/04/30 01:28:15 INFO : sub dir: Set directory modification time (using DirSetModTime) 2025/04/30 01:28:15 DEBUG : Added delayed dir = "sub dir", newDst= 2025/04/30 01:28:15 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2025/04/30 01:28:15 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-sabikek0yata': Waiting for checks to finish 2025/04/30 01:28:15 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-sabikek0yata': Waiting for transfers to finish 2025/04/30 01:28:18 DEBUG : sub dir/hello world: md5 = 126a33786f3c7f94aa705140073adaeb OK 2025/04/30 01:28:18 INFO : sub dir/hello world: Copied (new) 2025/04/30 01:28:18 INFO : sub dir: Set directory modification time (using DirSetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-sabikek0yata'", Local "Local file system at /tmp/rclone1466900237", Modify Window "1ms" 2025/04/30 01:28:20 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestCopy (6.27s) === RUN TestCopyMetadata run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-sabikek0yata'", Local "Local file system at /tmp/rclone1466900237", Modify Window "1ms" 2025/04/30 01:28:21 DEBUG : metadata sub dir: Making directory with metadata 2025/04/30 01:28:21 INFO : metadata sub dir: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2025/04/30 01:28:21 DEBUG : empty metadata sub dir: Making directory with metadata 2025/04/30 01:28:21 INFO : empty metadata sub dir: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2025/04/30 01:28:21 DEBUG : Local file system at /tmp/rclone1466900237: File to upload is small (21 bytes), uploading instead of streaming 2025/04/30 01:28:21 DEBUG : metadata sub dir/hello metadata world: md5 = baa7a013449dbba2b1ed02b5cfb4e1a2 OK 2025/04/30 01:28:21 DEBUG : metadata sub dir/hello metadata world: Size and md5 of src and dst objects identical 2025/04/30 01:28:21 INFO : metadata sub dir: Set directory modification time (using DirSetModTime) 2025/04/30 01:28:22 DEBUG : Google drive root 'crypt/pil0n1qm7plo2mg2ir1k4f8njnr2gsmbacqrr6opdumvh038dtog': Skipping btime metadata as can't update it on an existing file: 2025-04-30T01:28:21.880828843Z 2025/04/30 01:28:22 INFO : empty metadata sub dir: Updated directory metadata 2025/04/30 01:28:23 DEBUG : Google drive root 'crypt/pil0n1qm7plo2mg2ir1k4f8njnr2gsmbacqrr6opdumvh038dtog': Skipping btime metadata as can't update it on an existing file: 2025-04-30T01:28:21.880828843Z 2025/04/30 01:28:23 INFO : metadata sub dir: Updated directory metadata 2025/04/30 01:28:23 DEBUG : metadata sub dir/hello metadata world: Need to transfer - File not found at Destination 2025/04/30 01:28:23 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-sabikek0yata': Waiting for checks to finish 2025/04/30 01:28:23 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-sabikek0yata': Waiting for transfers to finish 2025/04/30 01:28:25 DEBUG : metadata sub dir/hello metadata world: md5 = 6851e80a23d387faa1098f93600b7dcb OK 2025/04/30 01:28:25 INFO : metadata sub dir/hello metadata world: Copied (new) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-sabikek0yata'", Local "Local file system at /tmp/rclone1466900237", Modify Window "1ms" 2025/04/30 01:28:27 DEBUG : fg45q1rm3kh00nmmkk4m6ihmrcnel1p7551kqhjr9bk2gtd2gbf0: Rmdir: contains trashed file: "dmuvulfij81f693ur0f1vvbvq9v6iscp56daas3m51n9li5e3470" --- PASS: TestCopyMetadata (7.50s) === RUN TestCopyMetadataNoEmptyDirs run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-sabikek0yata'", Local "Local file system at /tmp/rclone1466900237", Modify Window "1ms" 2025/04/30 01:28:29 DEBUG : metadata sub dir: Making directory with metadata 2025/04/30 01:28:29 INFO : metadata sub dir: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2025/04/30 01:28:29 DEBUG : empty metadata sub dir: Making directory with metadata 2025/04/30 01:28:29 INFO : empty metadata sub dir: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2025/04/30 01:28:29 DEBUG : Local file system at /tmp/rclone1466900237: File to upload is small (21 bytes), uploading instead of streaming 2025/04/30 01:28:29 DEBUG : metadata sub dir/hello metadata world: md5 = baa7a013449dbba2b1ed02b5cfb4e1a2 OK 2025/04/30 01:28:29 DEBUG : metadata sub dir/hello metadata world: Size and md5 of src and dst objects identical 2025/04/30 01:28:29 INFO : metadata sub dir: Set directory modification time (using DirSetModTime) 2025/04/30 01:28:29 DEBUG : Added delayed dir = "empty metadata sub dir", newDst= 2025/04/30 01:28:29 DEBUG : Added delayed dir = "metadata sub dir", newDst= 2025/04/30 01:28:29 DEBUG : metadata sub dir/hello metadata world: Need to transfer - File not found at Destination 2025/04/30 01:28:29 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-sabikek0yata': Waiting for checks to finish 2025/04/30 01:28:29 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-sabikek0yata': Waiting for transfers to finish 2025/04/30 01:28:31 DEBUG : metadata sub dir/hello metadata world: md5 = f6596ee20d614fe8b81977b582bb1c72 OK 2025/04/30 01:28:31 INFO : metadata sub dir/hello metadata world: Copied (new) 2025/04/30 01:28:31 DEBUG : Google drive root 'crypt/pil0n1qm7plo2mg2ir1k4f8njnr2gsmbacqrr6opdumvh038dtog': Skipping btime metadata as can't update it on an existing file: 2025-04-30T01:28:29.3808365Z 2025/04/30 01:28:32 INFO : metadata sub dir: Updated directory metadata run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-sabikek0yata'", Local "Local file system at /tmp/rclone1466900237", Modify Window "1ms" 2025/04/30 01:28:34 DEBUG : fg45q1rm3kh00nmmkk4m6ihmrcnel1p7551kqhjr9bk2gtd2gbf0: Rmdir: contains trashed file: "dmuvulfij81f693ur0f1vvbvq9v6iscp56daas3m51n9li5e3470" --- PASS: TestCopyMetadataNoEmptyDirs (6.63s) === RUN TestCopyMissingDirectory run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-sabikek0yata'", Local "Local file system at /tmp/rclone1466900237", Modify Window "1ms" 2025/04/30 01:28:36 DEBUG : Creating backend with remote "/non-existing" 2025/04/30 01:28:36 ERROR : Local file system at /non-existing: error reading source root directory: directory not found 2025/04/30 01:28:36 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-sabikek0yata': Waiting for checks to finish 2025/04/30 01:28:36 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-sabikek0yata': Waiting for transfers to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-sabikek0yata'", Local "Local file system at /tmp/rclone1466900237", Modify Window "1ms" --- PASS: TestCopyMissingDirectory (1.08s) === RUN TestCopyNoTraverse run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-sabikek0yata'", Local "Local file system at /tmp/rclone1466900237", Modify Window "1ms" 2025/04/30 01:28:37 DEBUG : Added delayed dir = "sub dir", newDst= 2025/04/30 01:28:37 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2025/04/30 01:28:37 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-sabikek0yata': Waiting for checks to finish 2025/04/30 01:28:37 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-sabikek0yata': Waiting for transfers to finish 2025/04/30 01:28:39 DEBUG : sub dir/hello world: md5 = ce84b93b43b3e3359e5c8f9d78e948ea OK 2025/04/30 01:28:39 INFO : sub dir/hello world: Copied (new) 2025/04/30 01:28:40 INFO : sub dir: Set directory modification time (using DirSetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-sabikek0yata'", Local "Local file system at /tmp/rclone1466900237", Modify Window "1ms" 2025/04/30 01:28:41 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestCopyNoTraverse (5.88s) === RUN TestCopyCheckFirst run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-sabikek0yata'", Local "Local file system at /tmp/rclone1466900237", Modify Window "1ms" 2025/04/30 01:28:42 INFO : Encrypted drive 'TestCryptDrive:rclone-test-sabikek0yata': Running all checks before starting transfers 2025/04/30 01:28:43 DEBUG : Added delayed dir = "sub dir", newDst= 2025/04/30 01:28:43 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2025/04/30 01:28:43 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-sabikek0yata': Waiting for checks to finish 2025/04/30 01:28:43 INFO : Encrypted drive 'TestCryptDrive:rclone-test-sabikek0yata': Checks finished, now starting transfers 2025/04/30 01:28:43 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-sabikek0yata': Waiting for transfers to finish 2025/04/30 01:28:45 DEBUG : sub dir/hello world: md5 = 19e7e008e46db54ee118b290461e5b2d OK 2025/04/30 01:28:45 INFO : sub dir/hello world: Copied (new) 2025/04/30 01:28:45 INFO : sub dir: Set directory modification time (using DirSetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-sabikek0yata'", Local "Local file system at /tmp/rclone1466900237", Modify Window "1ms" 2025/04/30 01:28:47 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestCopyCheckFirst (5.58s) === RUN TestSyncNoTraverse run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-sabikek0yata'", Local "Local file system at /tmp/rclone1466900237", Modify Window "1ms" 2025/04/30 01:28:48 ERROR : Ignoring --no-traverse with sync 2025/04/30 01:28:48 DEBUG : Added delayed dir = "sub dir", newDst= 2025/04/30 01:28:48 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2025/04/30 01:28:48 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-sabikek0yata': Waiting for checks to finish 2025/04/30 01:28:48 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-sabikek0yata': Waiting for transfers to finish 2025/04/30 01:28:51 DEBUG : sub dir/hello world: md5 = 01902b7e33223062f8d3078867d886fa OK 2025/04/30 01:28:51 INFO : sub dir/hello world: Copied (new) 2025/04/30 01:28:51 DEBUG : Waiting for deletions to finish 2025/04/30 01:28:51 INFO : sub dir: Set directory modification time (using DirSetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-sabikek0yata'", Local "Local file system at /tmp/rclone1466900237", Modify Window "1ms" 2025/04/30 01:28:53 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestSyncNoTraverse (5.99s) === RUN TestCopyWithDepth run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-sabikek0yata'", Local "Local file system at /tmp/rclone1466900237", Modify Window "1ms" 2025/04/30 01:28:54 DEBUG : hello world2: Need to transfer - File not found at Destination 2025/04/30 01:28:54 DEBUG : Added delayed dir = "sub dir", newDst= 2025/04/30 01:28:54 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-sabikek0yata': Waiting for checks to finish 2025/04/30 01:28:54 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-sabikek0yata': Waiting for transfers to finish 2025/04/30 01:28:56 DEBUG : hello world2: md5 = 33deaf43d5b9c711bb66cb94c0f42baa OK 2025/04/30 01:28:56 INFO : hello world2: Copied (new) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-sabikek0yata'", Local "Local file system at /tmp/rclone1466900237", Modify Window "1ms" --- PASS: TestCopyWithDepth (3.05s) === RUN TestCopyWithFilesFrom run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-sabikek0yata'", Local "Local file system at /tmp/rclone1466900237", Modify Window "1ms" 2025/04/30 01:28:57 DEBUG : potato2: Need to transfer - File not found at Destination 2025/04/30 01:28:57 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-sabikek0yata': Waiting for checks to finish 2025/04/30 01:28:57 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-sabikek0yata': Waiting for transfers to finish 2025/04/30 01:28:59 DEBUG : potato2: md5 = 3a392223c317228a8ab646fadd5ea7eb OK 2025/04/30 01:28:59 INFO : potato2: Copied (new) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-sabikek0yata'", Local "Local file system at /tmp/rclone1466900237", Modify Window "1ms" --- PASS: TestCopyWithFilesFrom (3.29s) === RUN TestCopyWithFilesFromAndNoTraverse run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-sabikek0yata'", Local "Local file system at /tmp/rclone1466900237", Modify Window "1ms" 2025/04/30 01:29:01 DEBUG : potato2: Need to transfer - File not found at Destination 2025/04/30 01:29:01 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-sabikek0yata': Waiting for checks to finish 2025/04/30 01:29:01 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-sabikek0yata': Waiting for transfers to finish 2025/04/30 01:29:02 DEBUG : potato2: md5 = 1e45f912d98fe49ee9b59776a1474244 OK 2025/04/30 01:29:02 INFO : potato2: Copied (new) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-sabikek0yata'", Local "Local file system at /tmp/rclone1466900237", Modify Window "1ms" --- PASS: TestCopyWithFilesFromAndNoTraverse (3.30s) === RUN TestCopyEmptyDirectories run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-sabikek0yata'", Local "Local file system at /tmp/rclone1466900237", Modify Window "1ms" 2025/04/30 01:29:04 DEBUG : sub dir2/sub sub dir2: Making directory with metadata 2025/04/30 01:29:04 INFO : sub dir2/sub sub dir2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2025/04/30 01:29:04 INFO : sub dir2: Set directory modification time (using DirSetModTime) 2025/04/30 01:29:04 INFO : sub dir: Set directory modification time (using DirSetModTime) 2025/04/30 01:29:04 DEBUG : sub dir: Making directory with metadata 2025/04/30 01:29:05 INFO : sub dir: Made directory with metadata (mtime=2001-02-03T04:05:06.499999999Z) 2025/04/30 01:29:05 DEBUG : sub dir2: Making directory with metadata 2025/04/30 01:29:05 INFO : sub dir2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2025/04/30 01:29:05 DEBUG : sub dir2/sub sub dir2: Making directory with metadata 2025/04/30 01:29:05 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2025/04/30 01:29:06 INFO : sub dir2/sub sub dir2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2025/04/30 01:29:06 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-sabikek0yata': Waiting for checks to finish 2025/04/30 01:29:06 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-sabikek0yata': Waiting for transfers to finish 2025/04/30 01:29:07 DEBUG : sub dir/hello world: md5 = 7d3291f11c58949dbdde8aa93ada8daa OK 2025/04/30 01:29:07 INFO : sub dir/hello world: Copied (new) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-sabikek0yata'", Local "Local file system at /tmp/rclone1466900237", Modify Window "1ms" 2025/04/30 01:29:11 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc: Rmdir: contains trashed file: "cv6a9uf28ngrajena8kt5ijjn0" 2025/04/30 01:29:11 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestCopyEmptyDirectories (8.71s) === RUN TestCopyNoEmptyDirectories run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-sabikek0yata'", Local "Local file system at /tmp/rclone1466900237", Modify Window "1ms" 2025/04/30 01:29:12 INFO : sub dir2: Making directory 2025/04/30 01:29:12 DEBUG : sub dir2/sub sub dir2: Making directory with metadata 2025/04/30 01:29:12 INFO : sub dir2/sub sub dir2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2025/04/30 01:29:13 DEBUG : Added delayed dir = "sub dir", newDst= 2025/04/30 01:29:13 DEBUG : Added delayed dir = "sub dir2", newDst= 2025/04/30 01:29:13 DEBUG : Added delayed dir = "sub dir2/sub sub dir2", newDst= 2025/04/30 01:29:13 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2025/04/30 01:29:13 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-sabikek0yata': Waiting for checks to finish 2025/04/30 01:29:13 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-sabikek0yata': Waiting for transfers to finish 2025/04/30 01:29:15 DEBUG : sub dir/hello world: md5 = 8595b758a1f539d3776e6cce972786be OK 2025/04/30 01:29:15 INFO : sub dir/hello world: Copied (new) 2025/04/30 01:29:15 INFO : sub dir: Set directory modification time (using DirSetModTime) 2025/04/30 01:29:17 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestCopyNoEmptyDirectories (4.96s) === RUN TestMoveEmptyDirectories run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-sabikek0yata'", Local "Local file system at /tmp/rclone1466900237", Modify Window "1ms" 2025/04/30 01:29:17 DEBUG : sub dir2: Making directory with metadata 2025/04/30 01:29:17 INFO : sub dir2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2025/04/30 01:29:18 DEBUG : sub dir: Making directory with metadata 2025/04/30 01:29:18 INFO : sub dir: Made directory with metadata (mtime=2025-04-30T01:29:17.864886029Z) 2025/04/30 01:29:18 DEBUG : sub dir2: Making directory with metadata 2025/04/30 01:29:19 INFO : sub dir2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2025/04/30 01:29:19 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2025/04/30 01:29:19 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-sabikek0yata': Waiting for checks to finish 2025/04/30 01:29:19 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-sabikek0yata': Waiting for transfers to finish 2025/04/30 01:29:20 DEBUG : sub dir/hello world: md5 = 0d80f072e5892ad3bc42226b71660e5c OK 2025/04/30 01:29:20 INFO : sub dir/hello world: Copied (new) 2025/04/30 01:29:20 INFO : sub dir/hello world: Deleted run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-sabikek0yata'", Local "Local file system at /tmp/rclone1466900237", Modify Window "1ms" 2025/04/30 01:29:23 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestMoveEmptyDirectories (6.91s) === RUN TestSyncNoUpdateDirModtime run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-sabikek0yata'", Local "Local file system at /tmp/rclone1466900237", Modify Window "1ms" 2025/04/30 01:29:24 DEBUG : sub dir no update dir modtime: Making directory with metadata 2025/04/30 01:29:24 INFO : sub dir no update dir modtime: Made directory with metadata (mtime=2001-02-03T04:05:06.499999999Z) 2025/04/30 01:29:26 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-sabikek0yata': Waiting for checks to finish 2025/04/30 01:29:26 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-sabikek0yata': Waiting for transfers to finish 2025/04/30 01:29:26 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-sabikek0yata'", Local "Local file system at /tmp/rclone1466900237", Modify Window "1ms" --- PASS: TestSyncNoUpdateDirModtime (3.95s) === RUN TestMoveNoEmptyDirectories run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-sabikek0yata'", Local "Local file system at /tmp/rclone1466900237", Modify Window "1ms" 2025/04/30 01:29:28 INFO : sub dir2: Making directory 2025/04/30 01:29:28 DEBUG : Added delayed dir = "sub dir", newDst= 2025/04/30 01:29:28 DEBUG : Added delayed dir = "sub dir2", newDst= 2025/04/30 01:29:28 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2025/04/30 01:29:28 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-sabikek0yata': Waiting for checks to finish 2025/04/30 01:29:28 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-sabikek0yata': Waiting for transfers to finish 2025/04/30 01:29:31 DEBUG : sub dir/hello world: md5 = 835d67611db1fb8b006f9dcba5eb458d OK 2025/04/30 01:29:31 INFO : sub dir/hello world: Copied (new) 2025/04/30 01:29:31 INFO : sub dir/hello world: Deleted 2025/04/30 01:29:31 INFO : sub dir: Set directory modification time (using DirSetModTime) 2025/04/30 01:29:34 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestMoveNoEmptyDirectories (5.94s) === RUN TestSyncEmptyDirectories run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-sabikek0yata'", Local "Local file system at /tmp/rclone1466900237", Modify Window "1ms" 2025/04/30 01:29:34 DEBUG : sub dir2: Making directory with metadata 2025/04/30 01:29:34 INFO : sub dir2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2025/04/30 01:29:34 INFO : sub dir: Set directory modification time (using DirSetModTime) 2025/04/30 01:29:34 DEBUG : sub dir: Making directory with metadata 2025/04/30 01:29:35 INFO : sub dir: Made directory with metadata (mtime=2001-02-03T04:05:06.499999999Z) 2025/04/30 01:29:35 DEBUG : sub dir2: Making directory with metadata 2025/04/30 01:29:36 INFO : sub dir2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2025/04/30 01:29:36 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2025/04/30 01:29:36 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-sabikek0yata': Waiting for checks to finish 2025/04/30 01:29:36 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-sabikek0yata': Waiting for transfers to finish 2025/04/30 01:29:37 DEBUG : sub dir/hello world: md5 = 9da8e9244b4e6b120fe75da34249a081 OK 2025/04/30 01:29:37 INFO : sub dir/hello world: Copied (new) 2025/04/30 01:29:37 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-sabikek0yata'", Local "Local file system at /tmp/rclone1466900237", Modify Window "1ms" 2025/04/30 01:29:40 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestSyncEmptyDirectories (6.95s) === RUN TestSyncSetDelayedModTimes run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-sabikek0yata'", Local "Local file system at /tmp/rclone1466900237", 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-sabikek0yata'", Local "Local file system at /tmp/rclone1466900237", Modify Window "1ms" 2025/04/30 01:29:42 INFO : sub dir2: Making directory 2025/04/30 01:29:42 DEBUG : Added delayed dir = "sub dir", newDst= 2025/04/30 01:29:42 DEBUG : Added delayed dir = "sub dir2", newDst= 2025/04/30 01:29:42 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2025/04/30 01:29:42 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-sabikek0yata': Waiting for checks to finish 2025/04/30 01:29:42 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-sabikek0yata': Waiting for transfers to finish 2025/04/30 01:29:44 DEBUG : sub dir/hello world: md5 = a6974f86697c85465f5750954960072b OK 2025/04/30 01:29:44 INFO : sub dir/hello world: Copied (new) 2025/04/30 01:29:44 DEBUG : Waiting for deletions to finish 2025/04/30 01:29:44 INFO : sub dir: Set directory modification time (using DirSetModTime) 2025/04/30 01:29:46 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestSyncNoEmptyDirectories (5.18s) === RUN TestServerSideCopy run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-sabikek0yata'", Local "Local file system at /tmp/rclone1466900237", Modify Window "1ms" 2025/04/30 01:29:49 DEBUG : sub dir/hello world: md5 = 4facbf0b6144977ab46c8f49a8ee8c72 OK 2025/04/30 01:29:49 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-ginedoj3wiwe" 2025/04/30 01:29:49 DEBUG : Creating backend with remote "TestDrive:crypt/5q7qjp8mocipv71c5mh8u7lpm8m5mbkniqgpl450roekvhojs270" sync_test.go:590: Server side copy (if possible) Encrypted drive 'TestCryptDrive:rclone-test-sabikek0yata' -> Encrypted drive 'TestCryptDrive:rclone-test-ginedoj3wiwe' 2025/04/30 01:29:51 DEBUG : Added delayed dir = "sub dir", newDst= 2025/04/30 01:29:51 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2025/04/30 01:29:51 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-ginedoj3wiwe': Waiting for checks to finish 2025/04/30 01:29:51 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-ginedoj3wiwe': Waiting for transfers to finish 2025/04/30 01:29:53 INFO : sub dir/hello world: Copied (server-side copy) 2025/04/30 01:29:54 INFO : sub dir: Set directory modification time (using DirSetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-sabikek0yata'", Local "Local file system at /tmp/rclone1466900237", Modify Window "1ms" 2025/04/30 01:29:54 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-ginedoj3wiwe': Purge remote 2025/04/30 01:29:56 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestServerSideCopy (10.32s) === RUN TestCopyOverSelf run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-sabikek0yata'", Local "Local file system at /tmp/rclone1466900237", Modify Window "1ms" 2025/04/30 01:29:59 DEBUG : sub dir/hello world: md5 = fc3ccf25eb9bc6a3725e60771efd143f OK 2025/04/30 01:30:01 INFO : sub dir: Set directory modification time (using SetModTime) 2025/04/30 01:30:01 DEBUG : Added delayed dir = "sub dir", newDst=sub dir 2025/04/30 01:30:01 DEBUG : sub dir/hello world: Sizes differ (src 17 vs dst 11) 2025/04/30 01:30:01 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-sabikek0yata': Waiting for checks to finish 2025/04/30 01:30:01 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-sabikek0yata': Waiting for transfers to finish 2025/04/30 01:30:02 DEBUG : sub dir/hello world: md5 = a87bba42aa459b9554bc8c7223412c8d OK 2025/04/30 01:30:02 INFO : sub dir/hello world: Copied (replaced existing) 2025/04/30 01:30:02 INFO : sub dir: Set directory modification time (using SetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-sabikek0yata'", Local "Local file system at /tmp/rclone1466900237", Modify Window "1ms" 2025/04/30 01:30:04 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestCopyOverSelf (7.76s) === RUN TestServerSideCopyOverSelf run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-sabikek0yata'", Local "Local file system at /tmp/rclone1466900237", Modify Window "1ms" 2025/04/30 01:30:07 DEBUG : sub dir/hello world: md5 = 5b8f7a1164f24fad078cfde244e96236 OK 2025/04/30 01:30:07 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-wiviqag1yuwi" 2025/04/30 01:30:08 DEBUG : Creating backend with remote "TestDrive:crypt/5qjf9rl5fcrehjl1c8d9oahelsj7jd47iguvte3mnj8vgnk4fb00" sync_test.go:626: Server side copy (if possible) Encrypted drive 'TestCryptDrive:rclone-test-sabikek0yata' -> Encrypted drive 'TestCryptDrive:rclone-test-wiviqag1yuwi' 2025/04/30 01:30:09 DEBUG : Added delayed dir = "sub dir", newDst= 2025/04/30 01:30:09 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2025/04/30 01:30:09 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wiviqag1yuwi': Waiting for checks to finish 2025/04/30 01:30:09 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wiviqag1yuwi': Waiting for transfers to finish 2025/04/30 01:30:11 INFO : sub dir/hello world: Copied (server-side copy) 2025/04/30 01:30:12 INFO : sub dir: Set directory modification time (using DirSetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-sabikek0yata'", Local "Local file system at /tmp/rclone1466900237", Modify Window "1ms" 2025/04/30 01:30:14 DEBUG : sub dir/hello world: md5 = 0773d7ec74b2d2a24d9ac1c845865fff OK 2025/04/30 01:30:15 DEBUG : sub dir: Directory modification time the same (differ by 0s, within tolerance 1ms) 2025/04/30 01:30:15 DEBUG : Added delayed dir = "sub dir", newDst=sub dir 2025/04/30 01:30:15 DEBUG : sub dir/hello world: Sizes differ (src 17 vs dst 11) 2025/04/30 01:30:15 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wiviqag1yuwi': Waiting for checks to finish 2025/04/30 01:30:15 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wiviqag1yuwi': Waiting for transfers to finish 2025/04/30 01:30:16 INFO : sub dir/hello world: Copied (server-side copy) 2025/04/30 01:30:17 INFO : sub dir: Set directory modification time (using SetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-sabikek0yata'", Local "Local file system at /tmp/rclone1466900237", Modify Window "1ms" 2025/04/30 01:30:17 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wiviqag1yuwi': Purge remote 2025/04/30 01:30:19 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestServerSideCopyOverSelf (15.80s) === RUN TestMoveOverSelf run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-sabikek0yata'", Local "Local file system at /tmp/rclone1466900237", Modify Window "1ms" 2025/04/30 01:30:23 DEBUG : sub dir/hello world: md5 = 8d78179fdd9b91254536b131cdab7a3b OK 2025/04/30 01:30:24 INFO : sub dir: Set directory modification time (using SetModTime) 2025/04/30 01:30:24 DEBUG : Added delayed dir = "sub dir", newDst=sub dir 2025/04/30 01:30:24 DEBUG : sub dir/hello world: Sizes differ (src 17 vs dst 11) 2025/04/30 01:30:24 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-sabikek0yata': Waiting for checks to finish 2025/04/30 01:30:24 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-sabikek0yata': Waiting for transfers to finish 2025/04/30 01:30:25 DEBUG : sub dir/hello world: md5 = 7ed3688c11c3164d08820e42efe409e9 OK 2025/04/30 01:30:25 INFO : sub dir/hello world: Copied (replaced existing) 2025/04/30 01:30:25 INFO : sub dir/hello world: Deleted 2025/04/30 01:30:26 INFO : sub dir: Set directory modification time (using SetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-sabikek0yata'", Local "Local file system at /tmp/rclone1466900237", Modify Window "1ms" 2025/04/30 01:30:27 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestMoveOverSelf (7.83s) === RUN TestServerSideMoveOverSelf run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-sabikek0yata'", Local "Local file system at /tmp/rclone1466900237", Modify Window "1ms" 2025/04/30 01:30:30 DEBUG : sub dir/hello world: md5 = 8db2a90f3673d1b5a64ea8a6f7d0d918 OK 2025/04/30 01:30:31 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-biremeb9rori" 2025/04/30 01:30:31 DEBUG : Config file has changed externally - reloading 2025/04/30 01:30:31 DEBUG : Creating backend with remote "TestDrive:crypt/hf5ust97pnfs8b303qbka5hbu2mr18ap1nhp9jecbmdp8ab6t9g0" sync_test.go:671: Server side copy (if possible) Encrypted drive 'TestCryptDrive:rclone-test-sabikek0yata' -> Encrypted drive 'TestCryptDrive:rclone-test-biremeb9rori' 2025/04/30 01:30:32 DEBUG : Added delayed dir = "sub dir", newDst= 2025/04/30 01:30:32 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2025/04/30 01:30:32 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-biremeb9rori': Waiting for checks to finish 2025/04/30 01:30:32 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-biremeb9rori': Waiting for transfers to finish 2025/04/30 01:30:35 INFO : sub dir/hello world: Copied (server-side copy) 2025/04/30 01:30:35 INFO : sub dir: Set directory modification time (using DirSetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-sabikek0yata'", Local "Local file system at /tmp/rclone1466900237", Modify Window "1ms" 2025/04/30 01:30:37 DEBUG : sub dir/hello world: md5 = a54dc616f6ca305f6b0fbf10c4b6d484 OK 2025/04/30 01:30:38 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-biremeb9rori': Using server-side directory move 2025/04/30 01:30:38 INFO : Encrypted drive 'TestCryptDrive:rclone-test-biremeb9rori': Server side directory move failed - fallback to file moves: can't copy directory - destination already exists 2025/04/30 01:30:38 DEBUG : sub dir: Directory modification time the same (differ by 0s, within tolerance 1ms) 2025/04/30 01:30:38 DEBUG : Added delayed dir = "sub dir", newDst=sub dir 2025/04/30 01:30:38 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-biremeb9rori': Waiting for checks to finish 2025/04/30 01:30:38 DEBUG : sub dir/hello world: Sizes differ (src 17 vs dst 11) 2025/04/30 01:30:38 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-biremeb9rori': Waiting for transfers to finish 2025/04/30 01:30:39 INFO : sub dir/hello world: Deleted 2025/04/30 01:30:39 INFO : sub dir/hello world: Moved (server-side) 2025/04/30 01:30:40 INFO : sub dir: Set directory modification time (using SetModTime) 2025/04/30 01:30:42 DEBUG : sub dir/hello world: md5 = ec8d5aec39d6a46d0de6a051455b8dd4 OK 2025/04/30 01:30:42 DEBUG : testing file moves 2025/04/30 01:30:43 DEBUG : sub dir: Directory modification time the same (differ by 0s, within tolerance 1ms) 2025/04/30 01:30:43 DEBUG : Added delayed dir = "sub dir", newDst=sub dir 2025/04/30 01:30:43 DEBUG : sub dir/hello world: Sizes differ (src 24 vs dst 17) 2025/04/30 01:30:43 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-biremeb9rori': Waiting for checks to finish 2025/04/30 01:30:43 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-biremeb9rori': Waiting for transfers to finish 2025/04/30 01:30:43 INFO : sub dir/hello world: Deleted 2025/04/30 01:30:44 INFO : sub dir/hello world: Moved (server-side) 2025/04/30 01:30:44 INFO : sub dir: Set directory modification time (using SetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-sabikek0yata'", Local "Local file system at /tmp/rclone1466900237", Modify Window "1ms" 2025/04/30 01:30:45 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-biremeb9rori': Purge remote --- PASS: TestServerSideMoveOverSelf (19.37s) === RUN TestCopyAfterDelete run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-sabikek0yata'", Local "Local file system at /tmp/rclone1466900237", Modify Window "1ms" 2025/04/30 01:30:50 DEBUG : sub dir/hello world: md5 = 619235bad3c1e61119c847a50ce263cd OK 2025/04/30 01:30:50 ERROR : : error listing: directory not found 2025/04/30 01:30:50 INFO : Local file system at /tmp/rclone1466900237: Making directory 2025/04/30 01:30:51 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-sabikek0yata': Waiting for checks to finish 2025/04/30 01:30:51 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-sabikek0yata': Waiting for transfers to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-sabikek0yata'", Local "Local file system at /tmp/rclone1466900237", Modify Window "1ms" 2025/04/30 01:30:53 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestCopyAfterDelete (5.86s) === RUN TestCopyRedownload run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-sabikek0yata'", Local "Local file system at /tmp/rclone1466900237", Modify Window "1ms" 2025/04/30 01:30:56 DEBUG : sub dir/hello world: md5 = 0e2d06dfc6fa43e913e3490b7f5e090d OK 2025/04/30 01:30:57 DEBUG : Added delayed dir = "sub dir", newDst= 2025/04/30 01:30:57 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2025/04/30 01:30:57 DEBUG : Local file system at /tmp/rclone1466900237: Waiting for checks to finish 2025/04/30 01:30:57 DEBUG : Local file system at /tmp/rclone1466900237: Waiting for transfers to finish 2025/04/30 01:30:58 DEBUG : sub dir/hello world.285f0a30.partial: renamed to: sub dir/hello world 2025/04/30 01:30:58 INFO : sub dir/hello world: Copied (new) 2025/04/30 01:30:58 INFO : sub dir: Set directory modification time (using DirSetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-sabikek0yata'", Local "Local file system at /tmp/rclone1466900237", Modify Window "1ms" 2025/04/30 01:30:59 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestCopyRedownload (6.21s) === RUN TestSyncBasedOnCheckSum run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-sabikek0yata'", Local "Local file system at /tmp/rclone1466900237", Modify Window "1ms" 2025/04/30 01:31:00 DEBUG : check sum: Need to transfer - File not found at Destination 2025/04/30 01:31:00 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-sabikek0yata': Waiting for checks to finish 2025/04/30 01:31:00 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-sabikek0yata': Waiting for transfers to finish 2025/04/30 01:31:01 DEBUG : check sum: md5 = 3e3fcaa0f49716db06a116bff3a2faf7 OK 2025/04/30 01:31:01 INFO : check sum: Copied (new) 2025/04/30 01:31:01 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-sabikek0yata'", Local "Local file system at /tmp/rclone1466900237", Modify Window "1ms" 2025/04/30 01:31:02 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-sabikek0yata': Waiting for checks to finish 2025/04/30 01:31:02 NOTICE: Encrypted drive 'TestCryptDrive:rclone-test-sabikek0yata': --checksum is in use but the source and destination have no hashes in common; falling back to --size-only 2025/04/30 01:31:02 DEBUG : check sum: Size of src and dst objects identical 2025/04/30 01:31:02 DEBUG : check sum: Unchanged skipping 2025/04/30 01:31:02 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-sabikek0yata': Waiting for transfers to finish 2025/04/30 01:31:02 DEBUG : Waiting for deletions to finish 2025/04/30 01:31:02 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-sabikek0yata'", Local "Local file system at /tmp/rclone1466900237", Modify Window "1ms" --- PASS: TestSyncBasedOnCheckSum (3.99s) === RUN TestSyncSizeOnly run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-sabikek0yata'", Local "Local file system at /tmp/rclone1466900237", Modify Window "1ms" 2025/04/30 01:31:04 DEBUG : sizeonly: Need to transfer - File not found at Destination 2025/04/30 01:31:04 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-sabikek0yata': Waiting for checks to finish 2025/04/30 01:31:04 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-sabikek0yata': Waiting for transfers to finish 2025/04/30 01:31:05 DEBUG : sizeonly: md5 = 2262e51dfdead6d4e864aefdb8e2d785 OK 2025/04/30 01:31:05 INFO : sizeonly: Copied (new) 2025/04/30 01:31:05 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-sabikek0yata'", Local "Local file system at /tmp/rclone1466900237", Modify Window "1ms" 2025/04/30 01:31:06 DEBUG : sizeonly: Sizes identical 2025/04/30 01:31:06 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-sabikek0yata': Waiting for checks to finish 2025/04/30 01:31:06 DEBUG : sizeonly: Unchanged skipping 2025/04/30 01:31:06 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-sabikek0yata': Waiting for transfers to finish 2025/04/30 01:31:06 DEBUG : Waiting for deletions to finish 2025/04/30 01:31:06 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-sabikek0yata'", Local "Local file system at /tmp/rclone1466900237", Modify Window "1ms" --- PASS: TestSyncSizeOnly (3.97s) === RUN TestSyncIgnoreSize run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-sabikek0yata'", Local "Local file system at /tmp/rclone1466900237", Modify Window "1ms" 2025/04/30 01:31:08 DEBUG : ignore-size: Need to transfer - File not found at Destination 2025/04/30 01:31:08 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-sabikek0yata': Waiting for checks to finish 2025/04/30 01:31:08 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-sabikek0yata': Waiting for transfers to finish 2025/04/30 01:31:09 DEBUG : ignore-size: md5 = 9f113bd2af24d1dfcb91ea703d896720 OK 2025/04/30 01:31:09 INFO : ignore-size: Copied (new) 2025/04/30 01:31:09 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-sabikek0yata'", Local "Local file system at /tmp/rclone1466900237", Modify Window "1ms" 2025/04/30 01:31:10 DEBUG : ignore-size: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/30 01:31:10 DEBUG : ignore-size: Unchanged skipping 2025/04/30 01:31:10 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-sabikek0yata': Waiting for checks to finish 2025/04/30 01:31:10 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-sabikek0yata': Waiting for transfers to finish 2025/04/30 01:31:10 DEBUG : Waiting for deletions to finish 2025/04/30 01:31:10 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-sabikek0yata'", Local "Local file system at /tmp/rclone1466900237", Modify Window "1ms" --- PASS: TestSyncIgnoreSize (3.90s) === RUN TestSyncIgnoreTimes run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-sabikek0yata'", Local "Local file system at /tmp/rclone1466900237", Modify Window "1ms" 2025/04/30 01:31:13 DEBUG : existing: md5 = c2ece0635337f43c01764fab149714c0 OK 2025/04/30 01:31:13 DEBUG : existing: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/30 01:31:13 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-sabikek0yata': Waiting for checks to finish 2025/04/30 01:31:13 DEBUG : existing: Unchanged skipping 2025/04/30 01:31:13 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-sabikek0yata': Waiting for transfers to finish 2025/04/30 01:31:13 DEBUG : Waiting for deletions to finish 2025/04/30 01:31:13 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-sabikek0yata'", Local "Local file system at /tmp/rclone1466900237", Modify Window "1ms" 2025/04/30 01:31:14 DEBUG : existing: Transferring unconditionally as --ignore-times is in use 2025/04/30 01:31:14 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-sabikek0yata': Waiting for checks to finish 2025/04/30 01:31:14 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-sabikek0yata': Waiting for transfers to finish 2025/04/30 01:31:15 DEBUG : existing: md5 = 80b85eab4ae4128f0fb39786e9e8c56d OK 2025/04/30 01:31:15 INFO : existing: Copied (replaced existing) 2025/04/30 01:31:15 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-sabikek0yata'", Local "Local file system at /tmp/rclone1466900237", Modify Window "1ms" --- PASS: TestSyncIgnoreTimes (5.21s) === RUN TestSyncIgnoreExisting run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-sabikek0yata'", Local "Local file system at /tmp/rclone1466900237", Modify Window "1ms" 2025/04/30 01:31:17 DEBUG : existing: Need to transfer - File not found at Destination 2025/04/30 01:31:17 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-sabikek0yata': Waiting for checks to finish 2025/04/30 01:31:17 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-sabikek0yata': Waiting for transfers to finish 2025/04/30 01:31:19 DEBUG : existing: md5 = 1480c76d4938c04a8eeef326059cd83c OK 2025/04/30 01:31:19 INFO : existing: Copied (new) 2025/04/30 01:31:19 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-sabikek0yata'", Local "Local file system at /tmp/rclone1466900237", Modify Window "1ms" 2025/04/30 01:31:19 DEBUG : existing: Destination exists, skipping 2025/04/30 01:31:19 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-sabikek0yata': Waiting for checks to finish 2025/04/30 01:31:19 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-sabikek0yata': Waiting for transfers to finish 2025/04/30 01:31:19 DEBUG : Waiting for deletions to finish 2025/04/30 01:31:19 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-sabikek0yata'", Local "Local file system at /tmp/rclone1466900237", Modify Window "1ms" --- PASS: TestSyncIgnoreExisting (4.22s) === RUN TestSyncIgnoreErrors run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-sabikek0yata'", Local "Local file system at /tmp/rclone1466900237", Modify Window "1ms" 2025/04/30 01:31:23 DEBUG : b/potato: md5 = 873517f0a0b00e8671a361ab90f7e329 OK 2025/04/30 01:31:25 DEBUG : c/non empty space: md5 = af5b316cc36d60110890dad81e67bf7a OK 2025/04/30 01:31:25 INFO : d: Making directory 2025/04/30 01:31:27 DEBUG : Added delayed dir = "a", newDst= 2025/04/30 01:31:27 INFO : c: Set directory modification time (using SetModTime) 2025/04/30 01:31:27 DEBUG : Added delayed dir = "c", newDst=c 2025/04/30 01:31:27 DEBUG : c/non empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/04/30 01:31:27 DEBUG : a/potato2: Need to transfer - File not found at Destination 2025/04/30 01:31:27 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-sabikek0yata': Waiting for checks to finish 2025/04/30 01:31:27 DEBUG : c/non empty space: Unchanged skipping 2025/04/30 01:31:27 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-sabikek0yata': Waiting for transfers to finish 2025/04/30 01:31:30 DEBUG : a/potato2: md5 = b2d5a1ec66f1920a0a8bf7bc10e011ab OK 2025/04/30 01:31:30 INFO : a/potato2: Copied (new) 2025/04/30 01:31:30 DEBUG : Waiting for deletions to finish 2025/04/30 01:31:30 INFO : b/potato: Deleted 2025/04/30 01:31:31 INFO : a: Set directory modification time (using DirSetModTime) 2025/04/30 01:31:31 INFO : d: Removing directory 2025/04/30 01:31:31 INFO : b: Removing directory 2025/04/30 01:31:32 DEBUG : 32d8ua6196mc1r7qkfog53rkg0: Rmdir: contains trashed file: "2m507n64kafsi59v9q71r281a4" 2025/04/30 01:31:32 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-sabikek0yata': deleted 2 directories run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-sabikek0yata'", Local "Local file system at /tmp/rclone1466900237", Modify Window "1ms" 2025/04/30 01:31:34 DEBUG : 3i9du405pfogq3ncai6pg7ouio: Rmdir: contains trashed file: "982d3pss7t5pn0il16r2foj31s" 2025/04/30 01:31:35 DEBUG : 2bsvlrk2ne1lfitm6tttcu0qt8: Rmdir: contains trashed file: "89l8renevh3mji1c8r1p7qn6tg" --- PASS: TestSyncIgnoreErrors (14.89s) === RUN TestSyncAfterChangingModtimeOnly run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-sabikek0yata'", Local "Local file system at /tmp/rclone1466900237", Modify Window "1ms" 2025/04/30 01:31:37 DEBUG : empty space: md5 = b7e0335955b59ace175af9f615b811cf OK 2025/04/30 01:31:38 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-sabikek0yata': Waiting for checks to finish 2025/04/30 01:31:38 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/04/30 01:31:38 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-sabikek0yata': Waiting for transfers to finish 2025/04/30 01:31:38 NOTICE: empty space: Skipped copy as --dry-run is set (size 1) 2025/04/30 01:31:38 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-sabikek0yata'", Local "Local file system at /tmp/rclone1466900237", Modify Window "1ms" 2025/04/30 01:31:38 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-sabikek0yata': Waiting for checks to finish 2025/04/30 01:31:38 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/04/30 01:31:38 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-sabikek0yata': Waiting for transfers to finish 2025/04/30 01:31:40 DEBUG : empty space: md5 = 6b00d51d465bcfa8088213f2e8db6564 OK 2025/04/30 01:31:40 INFO : empty space: Copied (replaced existing) 2025/04/30 01:31:40 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-sabikek0yata'", Local "Local file system at /tmp/rclone1466900237", Modify Window "1ms" --- PASS: TestSyncAfterChangingModtimeOnly (5.52s) === RUN TestSyncAfterChangingModtimeOnlyWithNoUpdateModTime run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-sabikek0yata'", Local "Local file system at /tmp/rclone1466900237", Modify Window "1ms" sync_test.go:1016: Can't check this if no hashes supported --- PASS: TestSyncAfterChangingModtimeOnlyWithNoUpdateModTime (0.45s) === RUN TestSyncDoesntUpdateModtime run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-sabikek0yata'", Local "Local file system at /tmp/rclone1466900237", Modify Window "1ms" 2025/04/30 01:31:43 DEBUG : foo: md5 = 46d9794b87cdf599f3fdc9eb6f7e3939 OK 2025/04/30 01:31:44 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/04/30 01:31:44 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-sabikek0yata': Waiting for checks to finish 2025/04/30 01:31:44 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-sabikek0yata': Waiting for transfers to finish 2025/04/30 01:31:45 DEBUG : foo: md5 = 4d09f2dae3ada3e4d144374a4579bc8e OK 2025/04/30 01:31:45 INFO : foo: Copied (replaced existing) 2025/04/30 01:31:45 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-sabikek0yata'", Local "Local file system at /tmp/rclone1466900237", Modify Window "1ms" --- PASS: TestSyncDoesntUpdateModtime (4.54s) === RUN TestSyncAfterAddingAFile run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-sabikek0yata'", Local "Local file system at /tmp/rclone1466900237", Modify Window "1ms" 2025/04/30 01:31:48 DEBUG : empty space: md5 = 376935b602506e90de68d75c2f63d057 OK 2025/04/30 01:31:48 DEBUG : empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/04/30 01:31:48 DEBUG : potato: Need to transfer - File not found at Destination 2025/04/30 01:31:48 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-sabikek0yata': Waiting for checks to finish 2025/04/30 01:31:48 DEBUG : empty space: Unchanged skipping 2025/04/30 01:31:48 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-sabikek0yata': Waiting for transfers to finish 2025/04/30 01:31:50 DEBUG : potato: md5 = f442eecec864ae6e8eb56646d53cb5f7 OK 2025/04/30 01:31:50 INFO : potato: Copied (new) 2025/04/30 01:31:50 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-sabikek0yata'", Local "Local file system at /tmp/rclone1466900237", Modify Window "1ms" --- PASS: TestSyncAfterAddingAFile (5.33s) === RUN TestSyncAfterChangingFilesSizeOnly run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-sabikek0yata'", Local "Local file system at /tmp/rclone1466900237", Modify Window "1ms" 2025/04/30 01:31:53 DEBUG : potato: md5 = 3b2cefd90687aeb2e3a50b0cdcb62019 OK 2025/04/30 01:31:54 DEBUG : potato: Sizes differ (src 21 vs dst 60) 2025/04/30 01:31:54 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-sabikek0yata': Waiting for checks to finish 2025/04/30 01:31:54 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-sabikek0yata': Waiting for transfers to finish 2025/04/30 01:31:55 DEBUG : potato: md5 = 088bbd5684fcf6017b269692907ec312 OK 2025/04/30 01:31:55 INFO : potato: Copied (replaced existing) 2025/04/30 01:31:55 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-sabikek0yata'", Local "Local file system at /tmp/rclone1466900237", Modify Window "1ms" --- PASS: TestSyncAfterChangingFilesSizeOnly (4.81s) === RUN TestSyncAfterChangingContentsOnly run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-sabikek0yata'", Local "Local file system at /tmp/rclone1466900237", Modify Window "1ms" 2025/04/30 01:31:58 DEBUG : potato: md5 = 89571ecfdfb7e5b8d33cc17c47d697dd OK 2025/04/30 01:31:59 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-sabikek0yata': Waiting for checks to finish 2025/04/30 01:31:59 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/04/30 01:31:59 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-sabikek0yata': Waiting for transfers to finish 2025/04/30 01:32:00 DEBUG : potato: md5 = f35512b0272187700bab1b8a0afdb008 OK 2025/04/30 01:32:00 INFO : potato: Copied (replaced existing) 2025/04/30 01:32:00 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-sabikek0yata'", Local "Local file system at /tmp/rclone1466900237", Modify Window "1ms" --- PASS: TestSyncAfterChangingContentsOnly (4.63s) === RUN TestSyncAfterRemovingAFileAndAddingAFileDryRun run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-sabikek0yata'", Local "Local file system at /tmp/rclone1466900237", Modify Window "1ms" 2025/04/30 01:32:03 DEBUG : potato: md5 = 99c4f0957a2392b33b64fe1f0d98a2fb OK 2025/04/30 01:32:04 DEBUG : empty space: md5 = 65dab738337896f981088b4c0d0fe148 OK 2025/04/30 01:32:04 DEBUG : potato2: Need to transfer - File not found at Destination 2025/04/30 01:32:04 DEBUG : empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/04/30 01:32:04 DEBUG : empty space: Unchanged skipping 2025/04/30 01:32:04 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-sabikek0yata': Waiting for checks to finish 2025/04/30 01:32:04 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-sabikek0yata': Waiting for transfers to finish 2025/04/30 01:32:04 NOTICE: potato2: Skipped copy as --dry-run is set (size 60) 2025/04/30 01:32:04 DEBUG : Waiting for deletions to finish 2025/04/30 01:32:04 NOTICE: potato: Skipped delete as --dry-run is set (size 21) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-sabikek0yata'", Local "Local file system at /tmp/rclone1466900237", Modify Window "1ms" --- PASS: TestSyncAfterRemovingAFileAndAddingAFileDryRun (4.83s) === RUN TestSyncAfterRemovingAFileAndAddingAFile run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-sabikek0yata'", Local "Local file system at /tmp/rclone1466900237", Modify Window "1ms" 2025/04/30 01:32:08 DEBUG : potato: md5 = 01830e6fba2d4feb2b293a418929504b OK 2025/04/30 01:32:09 DEBUG : empty space: md5 = f28412b6a1d9166eead37aa1dae27c46 OK 2025/04/30 01:32:09 DEBUG : empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/04/30 01:32:09 DEBUG : potato2: Need to transfer - File not found at Destination 2025/04/30 01:32:09 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-sabikek0yata': Waiting for checks to finish 2025/04/30 01:32:09 DEBUG : empty space: Unchanged skipping 2025/04/30 01:32:09 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-sabikek0yata': Waiting for transfers to finish 2025/04/30 01:32:11 DEBUG : potato2: md5 = adec4980260a14c1c080f280147c6da9 OK 2025/04/30 01:32:11 INFO : potato2: Copied (new) 2025/04/30 01:32:11 DEBUG : Waiting for deletions to finish 2025/04/30 01:32:11 INFO : potato: Deleted run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-sabikek0yata'", Local "Local file system at /tmp/rclone1466900237", Modify Window "1ms" --- PASS: TestSyncAfterRemovingAFileAndAddingAFile (6.92s) === RUN TestSyncAfterRemovingAFileAndAddingAFileSubDir run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-sabikek0yata'", Local "Local file system at /tmp/rclone1466900237", Modify Window "1ms" 2025/04/30 01:32:15 DEBUG : b/potato: md5 = a036b99384cd8a12cb63035eb078651b OK 2025/04/30 01:32:17 DEBUG : c/non empty space: md5 = bdd234c1fd980f8b21207df1ff9cb72b OK 2025/04/30 01:32:17 INFO : d: Making directory 2025/04/30 01:32:18 INFO : d/e: Making directory 2025/04/30 01:32:20 DEBUG : Added delayed dir = "a", newDst= 2025/04/30 01:32:21 INFO : c: Set directory modification time (using SetModTime) 2025/04/30 01:32:21 DEBUG : Added delayed dir = "c", newDst=c 2025/04/30 01:32:21 DEBUG : a/potato2: Need to transfer - File not found at Destination 2025/04/30 01:32:21 DEBUG : c/non empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/04/30 01:32:21 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-sabikek0yata': Waiting for checks to finish 2025/04/30 01:32:21 DEBUG : c/non empty space: Unchanged skipping 2025/04/30 01:32:21 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-sabikek0yata': Waiting for transfers to finish 2025/04/30 01:32:23 DEBUG : a/potato2: md5 = 0163f32cc5818ab3f13f8b45137546a2 OK 2025/04/30 01:32:23 INFO : a/potato2: Copied (new) 2025/04/30 01:32:23 DEBUG : Waiting for deletions to finish 2025/04/30 01:32:23 INFO : b/potato: Deleted 2025/04/30 01:32:24 INFO : a: Set directory modification time (using DirSetModTime) 2025/04/30 01:32:24 INFO : d/e: Removing directory 2025/04/30 01:32:24 INFO : d: Removing directory 2025/04/30 01:32:25 DEBUG : ka6id8d20d3s5ktapedlphgta8: Rmdir: contains trashed file: "r8sppajuabeak3sbgj2ak8vuf8" 2025/04/30 01:32:25 INFO : b: Removing directory 2025/04/30 01:32:25 DEBUG : 32d8ua6196mc1r7qkfog53rkg0: Rmdir: contains trashed file: "2m507n64kafsi59v9q71r281a4" 2025/04/30 01:32:26 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-sabikek0yata': deleted 3 directories run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-sabikek0yata'", Local "Local file system at /tmp/rclone1466900237", Modify Window "1ms" 2025/04/30 01:32:28 DEBUG : 3i9du405pfogq3ncai6pg7ouio: Rmdir: contains trashed file: "982d3pss7t5pn0il16r2foj31s" 2025/04/30 01:32:29 DEBUG : 2bsvlrk2ne1lfitm6tttcu0qt8: Rmdir: contains trashed file: "89l8renevh3mji1c8r1p7qn6tg" --- PASS: TestSyncAfterRemovingAFileAndAddingAFileSubDir (16.62s) === RUN TestSyncAfterRemovingAFileAndAddingAFileSubDirWithErrors run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-sabikek0yata'", Local "Local file system at /tmp/rclone1466900237", Modify Window "1ms" 2025/04/30 01:32:32 DEBUG : b/potato: md5 = e1538c409a9054ad994527d9f0446691 OK 2025/04/30 01:32:34 DEBUG : c/non empty space: md5 = e3b790dea9cac71bd16d35f5b4bab224 OK 2025/04/30 01:32:34 INFO : d: Making directory 2025/04/30 01:32:36 DEBUG : Added delayed dir = "a", newDst= 2025/04/30 01:32:36 INFO : c: Set directory modification time (using SetModTime) 2025/04/30 01:32:36 DEBUG : Added delayed dir = "c", newDst=c 2025/04/30 01:32:36 DEBUG : c/non empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/04/30 01:32:36 DEBUG : c/non empty space: Unchanged skipping 2025/04/30 01:32:36 DEBUG : a/potato2: Need to transfer - File not found at Destination 2025/04/30 01:32:36 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-sabikek0yata': Waiting for checks to finish 2025/04/30 01:32:36 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-sabikek0yata': Waiting for transfers to finish 2025/04/30 01:32:38 DEBUG : a/potato2: md5 = 8220b34dde7858dd3eb22545b2a1f81f OK 2025/04/30 01:32:38 INFO : a/potato2: Copied (new) 2025/04/30 01:32:38 ERROR : Encrypted drive 'TestCryptDrive:rclone-test-sabikek0yata': not deleting files as there were IO errors 2025/04/30 01:32:39 INFO : a: Set directory modification time (using DirSetModTime) 2025/04/30 01:32:39 ERROR : Encrypted drive 'TestCryptDrive:rclone-test-sabikek0yata': not deleting directories as there were IO errors run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-sabikek0yata'", Local "Local file system at /tmp/rclone1466900237", Modify Window "1ms" 2025/04/30 01:32:42 DEBUG : 3i9du405pfogq3ncai6pg7ouio: Rmdir: contains trashed file: "982d3pss7t5pn0il16r2foj31s" 2025/04/30 01:32:43 DEBUG : 32d8ua6196mc1r7qkfog53rkg0: Rmdir: contains trashed file: "2m507n64kafsi59v9q71r281a4" 2025/04/30 01:32:43 DEBUG : 2bsvlrk2ne1lfitm6tttcu0qt8: Rmdir: contains trashed file: "89l8renevh3mji1c8r1p7qn6tg" --- PASS: TestSyncAfterRemovingAFileAndAddingAFileSubDirWithErrors (14.59s) === RUN TestSyncDeleteAfter --- PASS: TestSyncDeleteAfter (0.00s) === RUN TestSyncDeleteDuring run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-sabikek0yata'", Local "Local file system at /tmp/rclone1466900237", Modify Window "1ms" 2025/04/30 01:32:46 DEBUG : potato: md5 = 981699422d3d74ec0c9530c2a722e61c OK 2025/04/30 01:32:47 DEBUG : empty space: md5 = 51e753bb262cc1f49074f45bdd6ae7dc OK 2025/04/30 01:32:47 DEBUG : Waiting for deletions to finish 2025/04/30 01:32:48 DEBUG : empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/04/30 01:32:48 DEBUG : potato2: Need to transfer - File not found at Destination 2025/04/30 01:32:48 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-sabikek0yata': Waiting for checks to finish 2025/04/30 01:32:48 DEBUG : empty space: Unchanged skipping 2025/04/30 01:32:48 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-sabikek0yata': Waiting for transfers to finish 2025/04/30 01:32:48 INFO : potato: Deleted 2025/04/30 01:32:49 DEBUG : potato2: md5 = 40ab6a8a7618ac7e692890d0955f99c5 OK 2025/04/30 01:32:49 INFO : potato2: Copied (new) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-sabikek0yata'", Local "Local file system at /tmp/rclone1466900237", Modify Window "1ms" --- PASS: TestSyncDeleteDuring (6.56s) === RUN TestSyncDeleteBefore run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-sabikek0yata'", Local "Local file system at /tmp/rclone1466900237", Modify Window "1ms" 2025/04/30 01:32:52 DEBUG : potato: md5 = 40ff770f87508dc1fb396d5b8ed94b9a OK 2025/04/30 01:32:53 DEBUG : empty space: md5 = fac6c9021f11d8dd38a3ab45a7228dc5 OK 2025/04/30 01:32:54 DEBUG : Waiting for deletions to finish 2025/04/30 01:32:54 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-sabikek0yata': Waiting for checks to finish 2025/04/30 01:32:54 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-sabikek0yata': Waiting for transfers to finish 2025/04/30 01:32:54 INFO : potato: Deleted 2025/04/30 01:32:55 DEBUG : empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/04/30 01:32:55 DEBUG : potato2: Need to transfer - File not found at Destination 2025/04/30 01:32:55 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-sabikek0yata': Waiting for checks to finish 2025/04/30 01:32:55 DEBUG : empty space: Unchanged skipping 2025/04/30 01:32:55 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-sabikek0yata': Waiting for transfers to finish 2025/04/30 01:32:56 DEBUG : potato2: md5 = 7f428991df002f2b3eadfa286090bc53 OK 2025/04/30 01:32:56 INFO : potato2: Copied (new) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-sabikek0yata'", Local "Local file system at /tmp/rclone1466900237", Modify Window "1ms" --- PASS: TestSyncDeleteBefore (7.19s) === RUN TestCopyDeleteBefore run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-sabikek0yata'", Local "Local file system at /tmp/rclone1466900237", Modify Window "1ms" 2025/04/30 01:32:59 DEBUG : potato: md5 = 184c630befbc653d7d11cab55f2bae71 OK 2025/04/30 01:33:00 DEBUG : potato2: Need to transfer - File not found at Destination 2025/04/30 01:33:00 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-sabikek0yata': Waiting for checks to finish 2025/04/30 01:33:00 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-sabikek0yata': Waiting for transfers to finish 2025/04/30 01:33:01 DEBUG : potato2: md5 = 5b61581a6580efeaa433602b7a7194bf OK 2025/04/30 01:33:01 INFO : potato2: Copied (new) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-sabikek0yata'", Local "Local file system at /tmp/rclone1466900237", Modify Window "1ms" --- PASS: TestCopyDeleteBefore (5.51s) === RUN TestSyncWithExclude run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-sabikek0yata'", Local "Local file system at /tmp/rclone1466900237", Modify Window "1ms" 2025/04/30 01:33:05 DEBUG : potato2: md5 = 281b151e9c94b7ddccbb24910a9625c8 OK 2025/04/30 01:33:06 DEBUG : empty space: md5 = 4b3a8bb25f076976a43085bff8cd2846 OK 2025/04/30 01:33:06 DEBUG : enormous: Excluded (Size Filter) 2025/04/30 01:33:06 DEBUG : enormous: Excluded 2025/04/30 01:33:06 DEBUG : potato2: Excluded (Size Filter) 2025/04/30 01:33:06 DEBUG : potato2: Excluded 2025/04/30 01:33:07 DEBUG : potato2: Excluded (Size Filter) 2025/04/30 01:33:07 DEBUG : empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/04/30 01:33:07 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-sabikek0yata': Waiting for checks to finish 2025/04/30 01:33:07 DEBUG : empty space: Unchanged skipping 2025/04/30 01:33:07 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-sabikek0yata': Waiting for transfers to finish 2025/04/30 01:33:07 DEBUG : Waiting for deletions to finish 2025/04/30 01:33:07 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-sabikek0yata'", Local "Local file system at /tmp/rclone1466900237", Modify Window "1ms" 2025/04/30 01:33:07 DEBUG : enormous: Excluded (Size Filter) 2025/04/30 01:33:07 DEBUG : enormous: Excluded 2025/04/30 01:33:07 DEBUG : potato2: Excluded (Size Filter) 2025/04/30 01:33:07 DEBUG : potato2: Excluded 2025/04/30 01:33:07 DEBUG : potato2: Excluded (Size Filter) 2025/04/30 01:33:07 DEBUG : Local file system at /tmp/rclone1466900237: Waiting for checks to finish 2025/04/30 01:33:07 DEBUG : empty space: Size and modification time the same (differ by 456.789µs, within tolerance 1ms) 2025/04/30 01:33:07 DEBUG : empty space: Unchanged skipping 2025/04/30 01:33:07 DEBUG : Local file system at /tmp/rclone1466900237: Waiting for transfers to finish 2025/04/30 01:33:07 DEBUG : Waiting for deletions to finish 2025/04/30 01:33:07 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-sabikek0yata'", Local "Local file system at /tmp/rclone1466900237", Modify Window "1ms" --- PASS: TestSyncWithExclude (6.04s) === RUN TestSyncWithExcludeAndDeleteExcluded run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-sabikek0yata'", Local "Local file system at /tmp/rclone1466900237", Modify Window "1ms" 2025/04/30 01:33:11 DEBUG : potato2: md5 = 30d9f599aad0c7f0d24f448622fdb5c3 OK 2025/04/30 01:33:12 DEBUG : empty space: md5 = 3557da87d80126575b83fd0e0d6a603a OK 2025/04/30 01:33:14 DEBUG : enormous: md5 = 2b88ad0648cfe4cd96d4d092405e6abc OK 2025/04/30 01:33:14 DEBUG : enormous: Excluded (Size Filter) 2025/04/30 01:33:14 DEBUG : enormous: Excluded 2025/04/30 01:33:14 DEBUG : potato2: Excluded (Size Filter) 2025/04/30 01:33:14 DEBUG : potato2: Excluded 2025/04/30 01:33:14 DEBUG : empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/04/30 01:33:14 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-sabikek0yata': Waiting for checks to finish 2025/04/30 01:33:14 DEBUG : empty space: Unchanged skipping 2025/04/30 01:33:14 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-sabikek0yata': Waiting for transfers to finish 2025/04/30 01:33:14 DEBUG : Waiting for deletions to finish 2025/04/30 01:33:15 INFO : potato2: Deleted 2025/04/30 01:33:15 INFO : enormous: Deleted 2025/04/30 01:33:15 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-sabikek0yata'", Local "Local file system at /tmp/rclone1466900237", Modify Window "1ms" 2025/04/30 01:33:15 DEBUG : empty space: Size and modification time the same (differ by 456.789µs, within tolerance 1ms) 2025/04/30 01:33:15 DEBUG : empty space: Unchanged skipping 2025/04/30 01:33:15 DEBUG : Local file system at /tmp/rclone1466900237: Waiting for checks to finish 2025/04/30 01:33:15 DEBUG : Local file system at /tmp/rclone1466900237: Waiting for transfers to finish 2025/04/30 01:33:15 DEBUG : Waiting for deletions to finish 2025/04/30 01:33:15 INFO : enormous: Deleted 2025/04/30 01:33:15 INFO : potato2: Deleted 2025/04/30 01:33:15 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-sabikek0yata'", Local "Local file system at /tmp/rclone1466900237", Modify Window "1ms" --- PASS: TestSyncWithExcludeAndDeleteExcluded (7.16s) === RUN TestSyncWithUpdateOlder run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-sabikek0yata'", Local "Local file system at /tmp/rclone1466900237", Modify Window "1ms" 2025/04/30 01:33:18 DEBUG : one: md5 = a348ef371e279efed330c99457417187 OK 2025/04/30 01:33:20 DEBUG : two: md5 = f87f7b78351b5c0130254f9029a305a7 OK 2025/04/30 01:33:21 DEBUG : three: md5 = 06ec6b64e6cc6cb8ab34952f75958b55 OK 2025/04/30 01:33:22 DEBUG : four: md5 = f7dcbbe87fbab8602dec00077362a871 OK 2025/04/30 01:33:23 DEBUG : five: Need to transfer - File not found at Destination 2025/04/30 01:33:23 DEBUG : one: Destination is newer than source, skipping 2025/04/30 01:33:23 DEBUG : three: Sizes identical 2025/04/30 01:33:23 DEBUG : four: Sizes differ (src 4 vs dst 8) 2025/04/30 01:33:23 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-sabikek0yata': Waiting for checks to finish 2025/04/30 01:33:23 DEBUG : four: Destination mod time is within 1s of source but files differ, transferring 2025/04/30 01:33:23 DEBUG : three: Destination mod time is within 1s of source and files identical, skipping 2025/04/30 01:33:23 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-sabikek0yata': Waiting for transfers to finish 2025/04/30 01:33:24 DEBUG : four: md5 = 3e0acb9653820eaa39a6db98684b3cac OK 2025/04/30 01:33:24 INFO : four: Copied (replaced existing) 2025/04/30 01:33:24 DEBUG : two: md5 = a9d19b40167faaf3b237a56c594ddafc OK 2025/04/30 01:33:24 INFO : two: Copied (replaced existing) 2025/04/30 01:33:24 DEBUG : five: md5 = ba4aaf3ae95600818027b4f0476748cf OK 2025/04/30 01:33:24 INFO : five: Copied (new) 2025/04/30 01:33:24 DEBUG : Waiting for deletions to finish sync_test.go:1449: Skip test with --checksum as no hashes supported --- PASS: TestSyncWithUpdateOlder (10.42s) === 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-sabikek0yata'", Local "Local file system at /tmp/rclone1466900237", Modify Window "1ms" sync_test.go:1538: Can track renames: false 2025/04/30 01:33:27 ERROR : Encrypted drive 'TestCryptDrive:rclone-test-sabikek0yata': Ignoring --track-renames as the source and destination do not have a common hash 2025/04/30 01:33:27 DEBUG : potato: Need to transfer - File not found at Destination 2025/04/30 01:33:27 DEBUG : yam: Need to transfer - File not found at Destination 2025/04/30 01:33:27 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-sabikek0yata': Waiting for checks to finish 2025/04/30 01:33:27 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-sabikek0yata': Waiting for transfers to finish 2025/04/30 01:33:29 DEBUG : potato: md5 = 3a98b895f4983db7118c0d5a3e7139d2 OK 2025/04/30 01:33:29 INFO : potato: Copied (new) 2025/04/30 01:33:29 DEBUG : yam: md5 = dc8a30b72076e8f3ef986ce7ccc63016 OK 2025/04/30 01:33:29 INFO : yam: Copied (new) 2025/04/30 01:33:29 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-sabikek0yata'", Local "Local file system at /tmp/rclone1466900237", Modify Window "1ms" 2025/04/30 01:33:29 ERROR : Encrypted drive 'TestCryptDrive:rclone-test-sabikek0yata': Ignoring --track-renames as the source and destination do not have a common hash 2025/04/30 01:33:29 DEBUG : potato: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/30 01:33:29 DEBUG : yaml: Need to transfer - File not found at Destination 2025/04/30 01:33:29 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-sabikek0yata': Waiting for checks to finish 2025/04/30 01:33:29 DEBUG : potato: Unchanged skipping 2025/04/30 01:33:29 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-sabikek0yata': Waiting for transfers to finish 2025/04/30 01:33:30 DEBUG : yaml: md5 = 08ad2e2520b4ca29f8e92f66931dab9b OK 2025/04/30 01:33:30 INFO : yaml: Copied (new) 2025/04/30 01:33:30 DEBUG : Waiting for deletions to finish 2025/04/30 01:33:31 INFO : yam: Deleted run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-sabikek0yata'", Local "Local file system at /tmp/rclone1466900237", Modify Window "1ms" --- PASS: TestSyncWithTrackRenames (6.20s) === RUN TestParseRenamesStrategyModtime --- PASS: TestParseRenamesStrategyModtime (0.00s) === RUN TestRenamesStrategyModtime --- PASS: TestRenamesStrategyModtime (0.00s) === RUN TestSyncWithTrackRenamesStrategyModtime run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-sabikek0yata'", Local "Local file system at /tmp/rclone1466900237", Modify Window "1ms" sync_test.go:1610: Can track renames: true 2025/04/30 01:33:34 INFO : Encrypted drive 'TestCryptDrive:rclone-test-sabikek0yata': Making map for --track-renames 2025/04/30 01:33:34 INFO : Encrypted drive 'TestCryptDrive:rclone-test-sabikek0yata': Finished making map for --track-renames 2025/04/30 01:33:34 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-sabikek0yata': Waiting for checks to finish 2025/04/30 01:33:34 DEBUG : potato: Need to transfer - No matching file found at Destination 2025/04/30 01:33:34 DEBUG : yam: Need to transfer - No matching file found at Destination 2025/04/30 01:33:34 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-sabikek0yata': Waiting for renames to finish 2025/04/30 01:33:34 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-sabikek0yata': Waiting for transfers to finish 2025/04/30 01:33:35 DEBUG : potato: md5 = 0c455f67ab23d3fb09599df81a83df91 OK 2025/04/30 01:33:35 INFO : potato: Copied (new) 2025/04/30 01:33:35 DEBUG : yam: md5 = 20ac804f5d71601f2c670b234667d33f OK 2025/04/30 01:33:35 INFO : yam: Copied (new) 2025/04/30 01:33:35 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-sabikek0yata'", Local "Local file system at /tmp/rclone1466900237", Modify Window "1ms" 2025/04/30 01:33:36 DEBUG : potato: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/30 01:33:36 INFO : Encrypted drive 'TestCryptDrive:rclone-test-sabikek0yata': Making map for --track-renames 2025/04/30 01:33:36 INFO : Encrypted drive 'TestCryptDrive:rclone-test-sabikek0yata': Finished making map for --track-renames 2025/04/30 01:33:36 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-sabikek0yata': Waiting for checks to finish 2025/04/30 01:33:36 DEBUG : potato: Unchanged skipping 2025/04/30 01:33:36 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-sabikek0yata': Waiting for renames to finish 2025/04/30 01:33:36 INFO : yam: Moved (server-side) to: yaml 2025/04/30 01:33:36 INFO : yaml: Renamed from "yam" 2025/04/30 01:33:36 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-sabikek0yata': Waiting for transfers to finish 2025/04/30 01:33:36 DEBUG : Waiting for deletions to finish 2025/04/30 01:33:36 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-sabikek0yata'", Local "Local file system at /tmp/rclone1466900237", Modify Window "1ms" --- PASS: TestSyncWithTrackRenamesStrategyModtime (5.39s) === RUN TestSyncWithTrackRenamesStrategyLeaf run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-sabikek0yata'", Local "Local file system at /tmp/rclone1466900237", Modify Window "1ms" sync_test.go:1649: Can track renames: true 2025/04/30 01:33:39 DEBUG : Added delayed dir = "sub", newDst= 2025/04/30 01:33:39 INFO : Encrypted drive 'TestCryptDrive:rclone-test-sabikek0yata': Making map for --track-renames 2025/04/30 01:33:39 INFO : Encrypted drive 'TestCryptDrive:rclone-test-sabikek0yata': Finished making map for --track-renames 2025/04/30 01:33:39 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-sabikek0yata': Waiting for checks to finish 2025/04/30 01:33:39 DEBUG : potato: Need to transfer - No matching file found at Destination 2025/04/30 01:33:39 DEBUG : sub/yam: Need to transfer - No matching file found at Destination 2025/04/30 01:33:39 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-sabikek0yata': Waiting for renames to finish 2025/04/30 01:33:39 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-sabikek0yata': Waiting for transfers to finish 2025/04/30 01:33:41 DEBUG : potato: md5 = 8ab664efb2c6208e3bf7317f95a8804b OK 2025/04/30 01:33:41 INFO : potato: Copied (new) 2025/04/30 01:33:41 DEBUG : sub/yam: md5 = 7e64896e136edecf5f66de849b548994 OK 2025/04/30 01:33:41 INFO : sub/yam: Copied (new) 2025/04/30 01:33:41 DEBUG : Waiting for deletions to finish 2025/04/30 01:33:42 INFO : sub: Set directory modification time (using DirSetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-sabikek0yata'", Local "Local file system at /tmp/rclone1466900237", Modify Window "1ms" 2025/04/30 01:33:42 DEBUG : potato: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/30 01:33:42 DEBUG : potato: Unchanged skipping 2025/04/30 01:33:43 INFO : sub: Set directory modification time (using SetModTime) 2025/04/30 01:33:43 DEBUG : Added delayed dir = "sub", newDst=sub 2025/04/30 01:33:43 INFO : Encrypted drive 'TestCryptDrive:rclone-test-sabikek0yata': Making map for --track-renames 2025/04/30 01:33:43 INFO : Encrypted drive 'TestCryptDrive:rclone-test-sabikek0yata': Finished making map for --track-renames 2025/04/30 01:33:43 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-sabikek0yata': Waiting for checks to finish 2025/04/30 01:33:43 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-sabikek0yata': Waiting for renames to finish 2025/04/30 01:33:44 INFO : sub/yam: Moved (server-side) to: yam 2025/04/30 01:33:44 INFO : yam: Renamed from "sub/yam" 2025/04/30 01:33:44 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-sabikek0yata': Waiting for transfers to finish 2025/04/30 01:33:44 DEBUG : Waiting for deletions to finish 2025/04/30 01:33:44 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-sabikek0yata'", Local "Local file system at /tmp/rclone1466900237", Modify Window "1ms" --- PASS: TestSyncWithTrackRenamesStrategyLeaf (8.66s) === RUN TestServerSideMoveLocal run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-sabikek0yata'", Local "Local file system at /tmp/rclone1466900237", Modify Window "1ms" 2025/04/30 01:33:47 DEBUG : Creating backend with remote "/tmp/rclone1466900237/dir1" 2025/04/30 01:33:47 DEBUG : Config file has changed externally - reloading 2025/04/30 01:33:47 DEBUG : Creating backend with remote "/tmp/rclone1466900237/dir2" 2025/04/30 01:33:47 DEBUG : Local file system at /tmp/rclone1466900237/dir2: Using server-side directory move 2025/04/30 01:33:47 INFO : Local file system at /tmp/rclone1466900237/dir2: Server side directory move failed - fallback to file moves: can't copy directory - destination already exists 2025/04/30 01:33:47 DEBUG : file1.txt: Need to transfer - File not found at Destination 2025/04/30 01:33:47 DEBUG : Local file system at /tmp/rclone1466900237/dir2: Waiting for checks to finish 2025/04/30 01:33:47 DEBUG : Local file system at /tmp/rclone1466900237/dir2: Waiting for transfers to finish 2025/04/30 01:33:47 INFO : file1.txt: Moved (server-side) --- PASS: TestServerSideMoveLocal (0.42s) === RUN TestMoveWithDeleteEmptySrcDirs run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-sabikek0yata'", Local "Local file system at /tmp/rclone1466900237", Modify Window "1ms" 2025/04/30 01:33:48 DEBUG : Added delayed dir = "nested", newDst= 2025/04/30 01:33:48 DEBUG : Added delayed dir = "sub dir", newDst= 2025/04/30 01:33:48 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2025/04/30 01:33:48 DEBUG : Added delayed dir = "nested/sub dir", newDst= 2025/04/30 01:33:48 DEBUG : nested/sub dir/file: Need to transfer - File not found at Destination 2025/04/30 01:33:48 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-sabikek0yata': Waiting for checks to finish 2025/04/30 01:33:48 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-sabikek0yata': Waiting for transfers to finish 2025/04/30 01:33:50 DEBUG : sub dir/hello world: md5 = d96135bccda574ab55d8554b45cce424 OK 2025/04/30 01:33:50 INFO : sub dir/hello world: Copied (new) 2025/04/30 01:33:50 INFO : sub dir/hello world: Deleted 2025/04/30 01:33:52 DEBUG : nested/sub dir/file: md5 = 126e263c482f9611c70576943fa7adfc OK 2025/04/30 01:33:52 INFO : nested/sub dir/file: Copied (new) 2025/04/30 01:33:52 INFO : nested/sub dir/file: Deleted 2025/04/30 01:33:52 INFO : nested/sub dir: Set directory modification time (using DirSetModTime) 2025/04/30 01:33:53 INFO : nested: Set directory modification time (using DirSetModTime) 2025/04/30 01:33:53 INFO : sub dir: Set directory modification time (using DirSetModTime) 2025/04/30 01:33:53 INFO : sub dir: Removing directory 2025/04/30 01:33:53 INFO : nested/sub dir: Removing directory 2025/04/30 01:33:53 INFO : nested: Removing directory 2025/04/30 01:33:53 DEBUG : Local file system at /tmp/rclone1466900237: deleted 3 directories run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-sabikek0yata'", Local "Local file system at /tmp/rclone1466900237", Modify Window "1ms" 2025/04/30 01:33:56 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" 2025/04/30 01:33:56 DEBUG : 37qp6d1gohacv723ij3brofbu8/14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "ftp4kuv8se7tqduu6pmmcvjsmk" 2025/04/30 01:33:57 DEBUG : 37qp6d1gohacv723ij3brofbu8: Rmdir: contains trashed file: "14begaa36ih249fgrnfk6nulg0" --- PASS: TestMoveWithDeleteEmptySrcDirs (11.18s) === RUN TestMoveWithoutDeleteEmptySrcDirs run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-sabikek0yata'", Local "Local file system at /tmp/rclone1466900237", Modify Window "1ms" 2025/04/30 01:33:59 DEBUG : Added delayed dir = "nested", newDst= 2025/04/30 01:33:59 DEBUG : Added delayed dir = "sub dir", newDst= 2025/04/30 01:33:59 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2025/04/30 01:33:59 DEBUG : Added delayed dir = "nested/sub dir", newDst= 2025/04/30 01:33:59 DEBUG : nested/sub dir/file: Need to transfer - File not found at Destination 2025/04/30 01:33:59 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-sabikek0yata': Waiting for checks to finish 2025/04/30 01:33:59 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-sabikek0yata': Waiting for transfers to finish 2025/04/30 01:34:01 DEBUG : sub dir/hello world: md5 = accef6bf79d650d025bb768c30fa1a52 OK 2025/04/30 01:34:01 INFO : sub dir/hello world: Copied (new) 2025/04/30 01:34:01 INFO : sub dir/hello world: Deleted 2025/04/30 01:34:03 DEBUG : nested/sub dir/file: md5 = 83f9966735c3bcbe6fb54810666f2923 OK 2025/04/30 01:34:03 INFO : nested/sub dir/file: Copied (new) 2025/04/30 01:34:03 INFO : nested/sub dir/file: Deleted 2025/04/30 01:34:03 INFO : nested/sub dir: Set directory modification time (using DirSetModTime) 2025/04/30 01:34:04 INFO : nested: Set directory modification time (using DirSetModTime) 2025/04/30 01:34:04 INFO : sub dir: Set directory modification time (using DirSetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-sabikek0yata'", Local "Local file system at /tmp/rclone1466900237", Modify Window "1ms" 2025/04/30 01:34:07 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" 2025/04/30 01:34:07 DEBUG : 37qp6d1gohacv723ij3brofbu8/14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "ftp4kuv8se7tqduu6pmmcvjsmk" 2025/04/30 01:34:08 DEBUG : 37qp6d1gohacv723ij3brofbu8: Rmdir: contains trashed file: "14begaa36ih249fgrnfk6nulg0" --- PASS: TestMoveWithoutDeleteEmptySrcDirs (10.08s) === RUN TestMoveWithIgnoreExisting run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-sabikek0yata'", Local "Local file system at /tmp/rclone1466900237", Modify Window "1ms" 2025/04/30 01:34:09 DEBUG : existing: Need to transfer - File not found at Destination 2025/04/30 01:34:09 DEBUG : existing-b: Need to transfer - File not found at Destination 2025/04/30 01:34:09 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-sabikek0yata': Waiting for checks to finish 2025/04/30 01:34:09 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-sabikek0yata': Waiting for transfers to finish 2025/04/30 01:34:11 DEBUG : existing-b: md5 = 8bf27fc64d94852c403bf89182a434bb OK 2025/04/30 01:34:11 INFO : existing-b: Copied (new) 2025/04/30 01:34:11 INFO : existing-b: Deleted 2025/04/30 01:34:11 DEBUG : existing: md5 = 7dbb0587fd9e844fbc93f2adb7346d59 OK 2025/04/30 01:34:11 INFO : existing: Copied (new) 2025/04/30 01:34:11 INFO : existing: Deleted 2025/04/30 01:34:11 DEBUG : existing: Destination exists, skipping 2025/04/30 01:34:11 DEBUG : existing: Not removing source file as destination file exists and --ignore-existing is set 2025/04/30 01:34:11 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-sabikek0yata': Waiting for checks to finish 2025/04/30 01:34:11 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-sabikek0yata': Waiting for transfers to finish 2025/04/30 01:34:11 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-sabikek0yata'", Local "Local file system at /tmp/rclone1466900237", Modify Window "1ms" --- PASS: TestMoveWithIgnoreExisting (4.23s) === RUN TestServerSideMove run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-sabikek0yata'", Local "Local file system at /tmp/rclone1466900237", Modify Window "1ms" 2025/04/30 01:34:13 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-dovewiq5nufe" 2025/04/30 01:34:13 DEBUG : Config file has changed externally - reloading 2025/04/30 01:34:13 DEBUG : Creating backend with remote "TestDrive:crypt/qfkmamukqb42fr5ghfpo2eklranbd9i8oho9cb1oqsbe7tep7630" 2025/04/30 01:34:16 DEBUG : potato2: md5 = 7c844a6e7e167238cbce94d0b9a562ad OK 2025/04/30 01:34:17 DEBUG : empty space: md5 = 74e47b697967d786649ec8edf963973d OK 2025/04/30 01:34:19 DEBUG : potato3: md5 = c3a5700e451bd2c2b5a0c4052f69f46b OK sync_test.go:1705: Server side move (if possible) Encrypted drive 'TestCryptDrive:rclone-test-sabikek0yata' -> Encrypted drive 'TestCryptDrive:rclone-test-dovewiq5nufe' 2025/04/30 01:34:21 DEBUG : empty space: md5 = 31f5cdbb793d321b0accc833421e5dfb OK 2025/04/30 01:34:22 DEBUG : potato3: md5 = a796bf47ed58d36f4a25c5d38b201427 OK 2025/04/30 01:34:23 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dovewiq5nufe': Using server-side directory move 2025/04/30 01:34:23 INFO : Encrypted drive 'TestCryptDrive:rclone-test-dovewiq5nufe': Server side directory move failed - fallback to file moves: can't copy directory - destination already exists 2025/04/30 01:34:23 DEBUG : potato2: Need to transfer - File not found at Destination 2025/04/30 01:34:23 DEBUG : empty space: Size and modification time the same (differ by 0s, within tolerance 1ms) 2025/04/30 01:34:23 DEBUG : empty space: Unchanged skipping 2025/04/30 01:34:23 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dovewiq5nufe': Waiting for checks to finish 2025/04/30 01:34:23 DEBUG : potato3: Sizes differ (src 68 vs dst 60) 2025/04/30 01:34:23 INFO : potato3: Deleted 2025/04/30 01:34:23 INFO : empty space: Deleted 2025/04/30 01:34:23 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dovewiq5nufe': Waiting for transfers to finish 2025/04/30 01:34:23 INFO : potato2: Moved (server-side) 2025/04/30 01:34:24 INFO : potato3: Moved (server-side) 2025/04/30 01:34:24 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-yoqujim8seji" 2025/04/30 01:34:24 DEBUG : Creating backend with remote "TestDrive:crypt/i92mdl65vkie84rm6hbl0qj0lq6qkba8g6uiq3keojcasstlblgg" 2025/04/30 01:34:25 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yoqujim8seji': Using server-side directory move 2025/04/30 01:34:26 INFO : Encrypted drive 'TestCryptDrive:rclone-test-yoqujim8seji': Server side directory move succeeded 2025/04/30 01:34:27 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yoqujim8seji': Purge remote 2025/04/30 01:34:28 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dovewiq5nufe': Purge remote 2025/04/30 01:34:28 NOTICE: purge failed: directory not found --- PASS: TestServerSideMove (14.86s) === RUN TestServerSideMoveWithFilter run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-sabikek0yata'", Local "Local file system at /tmp/rclone1466900237", Modify Window "1ms" 2025/04/30 01:34:28 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-kibipis4qoyi" 2025/04/30 01:34:28 DEBUG : Config file has changed externally - reloading 2025/04/30 01:34:28 DEBUG : Creating backend with remote "TestDrive:crypt/vcljrf6bj33ieu6f5fccodia5cogkhi826h3hvmf72qenjdgru2g" 2025/04/30 01:34:31 DEBUG : potato2: md5 = b8e46e6f308d88110e7c0cad11769e07 OK 2025/04/30 01:34:32 DEBUG : empty space: md5 = f26d776a8a7b59ee399918ba33f288f3 OK 2025/04/30 01:34:33 DEBUG : potato3: md5 = 08d65d05debc97d51c824de63d697cda OK sync_test.go:1705: Server side move (if possible) Encrypted drive 'TestCryptDrive:rclone-test-sabikek0yata' -> Encrypted drive 'TestCryptDrive:rclone-test-kibipis4qoyi' 2025/04/30 01:34:35 DEBUG : empty space: md5 = 968f0825b41c44fb048c40d22a433487 OK 2025/04/30 01:34:37 DEBUG : potato3: md5 = 094fa6bda27a0d1cf23300de37892bb8 OK 2025/04/30 01:34:37 DEBUG : empty space: Excluded (Size Filter) 2025/04/30 01:34:37 DEBUG : empty space: Excluded (Size Filter) 2025/04/30 01:34:37 DEBUG : potato2: Need to transfer - File not found at Destination 2025/04/30 01:34:37 DEBUG : potato3: Sizes differ (src 68 vs dst 60) 2025/04/30 01:34:37 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-kibipis4qoyi': Waiting for checks to finish 2025/04/30 01:34:37 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-kibipis4qoyi': Waiting for transfers to finish 2025/04/30 01:34:38 INFO : potato3: Deleted 2025/04/30 01:34:38 INFO : potato2: Moved (server-side) 2025/04/30 01:34:39 INFO : potato3: Moved (server-side) 2025/04/30 01:34:39 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-kisayeh9vine" 2025/04/30 01:34:39 DEBUG : Creating backend with remote "TestDrive:crypt/698aiop18587lglvp36f1hls8ttbgtkr98ilq3r8l5dhmr6pcqog" 2025/04/30 01:34:40 DEBUG : empty space: Excluded (Size Filter) 2025/04/30 01:34:40 DEBUG : potato2: Need to transfer - File not found at Destination 2025/04/30 01:34:40 DEBUG : potato3: Need to transfer - File not found at Destination 2025/04/30 01:34:40 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-kisayeh9vine': Waiting for checks to finish 2025/04/30 01:34:40 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-kisayeh9vine': Waiting for transfers to finish 2025/04/30 01:34:42 INFO : potato2: Moved (server-side) 2025/04/30 01:34:42 INFO : potato3: Moved (server-side) 2025/04/30 01:34:42 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-kisayeh9vine': Purge remote 2025/04/30 01:34:43 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-kibipis4qoyi': Purge remote --- PASS: TestServerSideMoveWithFilter (15.69s) === RUN TestServerSideMoveDeleteEmptySourceDirs run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-sabikek0yata'", Local "Local file system at /tmp/rclone1466900237", Modify Window "1ms" 2025/04/30 01:34:44 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-tazosid9gilo" 2025/04/30 01:34:44 DEBUG : Creating backend with remote "TestDrive:crypt/cnscvqoltma2ssqm13tkh38i4ubi67cvgb343n1gmtnkfa6j4h8g" 2025/04/30 01:34:47 DEBUG : potato2: md5 = 40924f87920f4aed87586101d7fc53e4 OK 2025/04/30 01:34:48 DEBUG : empty space: md5 = 572cb450c0db3b30a6695194c4242d71 OK 2025/04/30 01:34:49 DEBUG : potato3: md5 = 0020712beca992553205cf371ed776d6 OK 2025/04/30 01:34:49 INFO : tomatoDir: Making directory sync_test.go:1705: Server side move (if possible) Encrypted drive 'TestCryptDrive:rclone-test-sabikek0yata' -> Encrypted drive 'TestCryptDrive:rclone-test-tazosid9gilo' 2025/04/30 01:34:52 DEBUG : empty space: md5 = b20eae41ecaae0eb297ea4d3324b0421 OK 2025/04/30 01:34:54 DEBUG : potato3: md5 = d8bcf2e4591887aa07686651d072e7ce OK 2025/04/30 01:34:54 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tazosid9gilo': Using server-side directory move 2025/04/30 01:34:54 INFO : Encrypted drive 'TestCryptDrive:rclone-test-tazosid9gilo': Server side directory move failed - fallback to file moves: can't copy directory - destination already exists 2025/04/30 01:34:55 DEBUG : potato2: Need to transfer - File not found at Destination 2025/04/30 01:34:55 DEBUG : Added delayed dir = "tomatoDir", newDst= 2025/04/30 01:34:55 DEBUG : empty space: Size and modification time the same (differ by 0s, within tolerance 1ms) 2025/04/30 01:34:55 DEBUG : empty space: Unchanged skipping 2025/04/30 01:34:55 DEBUG : potato3: Sizes differ (src 68 vs dst 60) 2025/04/30 01:34:55 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tazosid9gilo': Waiting for checks to finish 2025/04/30 01:34:55 INFO : empty space: Deleted 2025/04/30 01:34:55 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tazosid9gilo': Waiting for transfers to finish 2025/04/30 01:34:55 INFO : potato3: Deleted 2025/04/30 01:34:55 INFO : potato2: Moved (server-side) 2025/04/30 01:34:56 INFO : potato3: Moved (server-side) 2025/04/30 01:34:56 INFO : tomatoDir: Removing directory 2025/04/30 01:34:56 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-sabikek0yata': deleted 1 directories 2025/04/30 01:34:57 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-haheray6xezi" 2025/04/30 01:34:57 DEBUG : Creating backend with remote "TestDrive:crypt/tiv9o0f2m3ch9a46sekp9g7b89bnth25tgir2auk165n0ir7ehb0" 2025/04/30 01:34:58 INFO : tomatoDir: Making directory 2025/04/30 01:34:59 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-haheray6xezi': Using server-side directory move 2025/04/30 01:35:00 INFO : Encrypted drive 'TestCryptDrive:rclone-test-haheray6xezi': Server side directory move succeeded 2025/04/30 01:35:01 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-haheray6xezi': Purge remote 2025/04/30 01:35:01 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tazosid9gilo': Purge remote 2025/04/30 01:35:02 NOTICE: purge failed: directory not found --- PASS: TestServerSideMoveDeleteEmptySourceDirs (18.15s) === RUN TestServerSideMoveOverlap run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-sabikek0yata'", Local "Local file system at /tmp/rclone1466900237", Modify Window "1ms" sync_test.go:1910: Skipping test as remote supports DirMove --- SKIP: TestServerSideMoveOverlap (0.43s) === RUN TestSyncOverlap run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-sabikek0yata'", Local "Local file system at /tmp/rclone1466900237", Modify Window "1ms" 2025/04/30 01:35:02 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-sabikek0yata/rclone-sync-test" 2025/04/30 01:35:03 DEBUG : Creating backend with remote "TestDrive:crypt/pil0n1qm7plo2mg2ir1k4f8njnr2gsmbacqrr6opdumvh038dtog/i7355aa0sb89uagn75vfjqr6s3e3e1h2et8in57abn1fe8qfego0" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-sabikek0yata'", Local "Local file system at /tmp/rclone1466900237", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-sabikek0yata'", Local "Local file system at /tmp/rclone1466900237", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-sabikek0yata'", Local "Local file system at /tmp/rclone1466900237", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-sabikek0yata'", Local "Local file system at /tmp/rclone1466900237", Modify Window "1ms" --- PASS: TestSyncOverlap (3.74s) === RUN TestSyncOverlapWithFilter run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-sabikek0yata'", Local "Local file system at /tmp/rclone1466900237", Modify Window "1ms" 2025/04/30 01:35:06 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-sabikek0yata/rclone-sync-test" 2025/04/30 01:35:06 DEBUG : Creating backend with remote "TestDrive:crypt/pil0n1qm7plo2mg2ir1k4f8njnr2gsmbacqrr6opdumvh038dtog/i7355aa0sb89uagn75vfjqr6s3e3e1h2et8in57abn1fe8qfego0" 2025/04/30 01:35:08 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-sabikek0yata/rclone-sync-test-include/layer2" 2025/04/30 01:35:08 DEBUG : Creating backend with remote "TestDrive:crypt/pil0n1qm7plo2mg2ir1k4f8njnr2gsmbacqrr6opdumvh038dtog/khf2vlblvnbf9ftevqm0htmss73hj1j5a7q328e4ohrgs7e2loe0/n01jpl9202nn9ec1rb75h0f1c4" 2025/04/30 01:35:12 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-sabikek0yata/rclone-sync-test-ignore-file" 2025/04/30 01:35:12 DEBUG : Creating backend with remote "TestDrive:crypt/pil0n1qm7plo2mg2ir1k4f8njnr2gsmbacqrr6opdumvh038dtog/kmf11jujl9uha3tjganvgpkn45bu778hb5vb5riug1c26b38k7sg" 2025/04/30 01:35:16 DEBUG : rclone-sync-test-ignore-file/.ignore: md5 = c6c68b8fb4790a2c6a659c5d48d78f4f OK 2025/04/30 01:35:18 DEBUG : Added delayed dir = "rclone-sync-test-include", newDst= 2025/04/30 01:35:18 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-sabikek0yata/rclone-sync-test': Waiting for checks to finish 2025/04/30 01:35:18 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-sabikek0yata/rclone-sync-test': Waiting for transfers to finish 2025/04/30 01:35:18 DEBUG : Waiting for deletions to finish 2025/04/30 01:35:18 INFO : There was nothing to transfer 2025/04/30 01:35:19 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-sabikek0yata': Waiting for checks to finish 2025/04/30 01:35:19 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-sabikek0yata': Waiting for transfers to finish 2025/04/30 01:35:19 DEBUG : Waiting for deletions to finish 2025/04/30 01:35:19 INFO : rclone-sync-test-include: Removing directory 2025/04/30 01:35:20 DEBUG : khf2vlblvnbf9ftevqm0htmss73hj1j5a7q328e4ohrgs7e2loe0: Rmdir: contains file: "n01jpl9202nn9ec1rb75h0f1c4" 2025/04/30 01:35:20 DEBUG : rclone-sync-test-include: Failed to Rmdir: directory not empty 2025/04/30 01:35:20 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-sabikek0yata': failed to delete 1 directories 2025/04/30 01:35:20 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-sabikek0yata'", Local "Local file system at /tmp/rclone1466900237", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-sabikek0yata'", Local "Local file system at /tmp/rclone1466900237", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-sabikek0yata'", Local "Local file system at /tmp/rclone1466900237", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-sabikek0yata'", Local "Local file system at /tmp/rclone1466900237", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-sabikek0yata'", Local "Local file system at /tmp/rclone1466900237", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-sabikek0yata'", Local "Local file system at /tmp/rclone1466900237", Modify Window "1ms" 2025/04/30 01:35:22 DEBUG : Added delayed dir = "rclone-sync-test-include", newDst= 2025/04/30 01:35:22 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-sabikek0yata/rclone-sync-test-include/layer2': Waiting for checks to finish 2025/04/30 01:35:22 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-sabikek0yata/rclone-sync-test-include/layer2': Waiting for transfers to finish 2025/04/30 01:35:22 DEBUG : Waiting for deletions to finish 2025/04/30 01:35:22 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-sabikek0yata'", Local "Local file system at /tmp/rclone1466900237", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-sabikek0yata'", Local "Local file system at /tmp/rclone1466900237", Modify Window "1ms" 2025/04/30 01:35:23 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-sabikek0yata': Waiting for checks to finish 2025/04/30 01:35:23 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-sabikek0yata': Waiting for transfers to finish 2025/04/30 01:35:23 DEBUG : Waiting for deletions to finish 2025/04/30 01:35:23 INFO : rclone-sync-test-include: Removing directory 2025/04/30 01:35:24 DEBUG : khf2vlblvnbf9ftevqm0htmss73hj1j5a7q328e4ohrgs7e2loe0: Rmdir: contains file: "n01jpl9202nn9ec1rb75h0f1c4" 2025/04/30 01:35:24 DEBUG : rclone-sync-test-include: Failed to Rmdir: directory not empty 2025/04/30 01:35:24 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-sabikek0yata': failed to delete 1 directories 2025/04/30 01:35:24 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-sabikek0yata'", Local "Local file system at /tmp/rclone1466900237", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-sabikek0yata'", Local "Local file system at /tmp/rclone1466900237", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-sabikek0yata'", Local "Local file system at /tmp/rclone1466900237", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-sabikek0yata'", Local "Local file system at /tmp/rclone1466900237", Modify Window "1ms" 2025/04/30 01:35:25 DEBUG : Added delayed dir = "rclone-sync-test-include", newDst= 2025/04/30 01:35:25 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-sabikek0yata/rclone-sync-test-ignore-file': Waiting for checks to finish 2025/04/30 01:35:25 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-sabikek0yata/rclone-sync-test-ignore-file': Waiting for transfers to finish 2025/04/30 01:35:25 DEBUG : Waiting for deletions to finish 2025/04/30 01:35:25 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-sabikek0yata'", Local "Local file system at /tmp/rclone1466900237", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-sabikek0yata'", Local "Local file system at /tmp/rclone1466900237", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-sabikek0yata'", Local "Local file system at /tmp/rclone1466900237", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-sabikek0yata'", Local "Local file system at /tmp/rclone1466900237", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-sabikek0yata'", Local "Local file system at /tmp/rclone1466900237", Modify Window "1ms" 2025/04/30 01:35:27 DEBUG : khf2vlblvnbf9ftevqm0htmss73hj1j5a7q328e4ohrgs7e2loe0: Rmdir: contains trashed file: "n01jpl9202nn9ec1rb75h0f1c4" 2025/04/30 01:35:28 DEBUG : kmf11jujl9uha3tjganvgpkn45bu778hb5vb5riug1c26b38k7sg: Rmdir: contains trashed file: "i0t74httmdlljg425j6tg570d8" --- PASS: TestSyncOverlapWithFilter (30.75s) === RUN TestSyncCompareDest run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-sabikek0yata'", Local "Local file system at /tmp/rclone1466900237", Modify Window "1ms" 2025/04/30 01:35:37 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-sabikek0yata/dst" 2025/04/30 01:35:37 DEBUG : Creating backend with remote "TestDrive:crypt/pil0n1qm7plo2mg2ir1k4f8njnr2gsmbacqrr6opdumvh038dtog/31u3jie661vd5p8j7rtc3hgbh0" 2025/04/30 01:35:38 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-sabikek0yata/CompareDest" 2025/04/30 01:35:39 DEBUG : Creating backend with remote "TestDrive:crypt/pil0n1qm7plo2mg2ir1k4f8njnr2gsmbacqrr6opdumvh038dtog/gveqi14airsml4bgu7krj116o8" 2025/04/30 01:35:40 DEBUG : one: Need to transfer - File not found at Destination 2025/04/30 01:35:40 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-sabikek0yata/dst': Waiting for checks to finish 2025/04/30 01:35:40 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-sabikek0yata/dst': Waiting for transfers to finish 2025/04/30 01:35:43 DEBUG : one: md5 = 9e29857c537b82464b0e77555fc13671 OK 2025/04/30 01:35:43 INFO : one: Copied (new) 2025/04/30 01:35:43 DEBUG : Waiting for deletions to finish 2025/04/30 01:35:44 DEBUG : one: Sizes differ (src 5 vs dst 3) 2025/04/30 01:35:44 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-sabikek0yata/dst': Waiting for checks to finish 2025/04/30 01:35:44 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-sabikek0yata/dst': Waiting for transfers to finish 2025/04/30 01:35:45 DEBUG : one: md5 = a3c4dd9e9b8a47b7fff357b5f2659a35 OK 2025/04/30 01:35:45 INFO : one: Copied (replaced existing) 2025/04/30 01:35:45 DEBUG : Waiting for deletions to finish 2025/04/30 01:35:47 DEBUG : dst/one: md5 = 9923bdebd7d35206405141cdf5367ab7 OK 2025/04/30 01:35:49 DEBUG : CompareDest/one: md5 = d7bb4b8589b7dae05e6718d7a69a80b2 OK 2025/04/30 01:35:50 DEBUG : one: Sizes differ (src 5 vs dst 3) 2025/04/30 01:35:50 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-sabikek0yata/dst': Waiting for checks to finish 2025/04/30 01:35:50 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/04/30 01:35:50 DEBUG : one: Destination found in --compare-dest, skipping 2025/04/30 01:35:50 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-sabikek0yata/dst': Waiting for transfers to finish 2025/04/30 01:35:50 DEBUG : Waiting for deletions to finish 2025/04/30 01:35:50 INFO : There was nothing to transfer 2025/04/30 01:35:52 DEBUG : CompareDest/two: md5 = 3977733798375c66a81fbd3d8bbfbb49 OK 2025/04/30 01:35:53 DEBUG : one: Sizes differ (src 5 vs dst 3) 2025/04/30 01:35:53 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/04/30 01:35:53 DEBUG : one: Destination found in --compare-dest, skipping 2025/04/30 01:35:53 DEBUG : two: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/04/30 01:35:53 DEBUG : two: Destination found in --compare-dest, skipping 2025/04/30 01:35:53 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-sabikek0yata/dst': Waiting for checks to finish 2025/04/30 01:35:53 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-sabikek0yata/dst': Waiting for transfers to finish 2025/04/30 01:35:53 DEBUG : Waiting for deletions to finish 2025/04/30 01:35:53 INFO : There was nothing to transfer 2025/04/30 01:35:53 DEBUG : one: Sizes differ (src 5 vs dst 3) 2025/04/30 01:35:54 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/04/30 01:35:54 DEBUG : one: Destination found in --compare-dest, skipping 2025/04/30 01:35:54 DEBUG : two: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/04/30 01:35:54 DEBUG : two: Destination found in --compare-dest, skipping 2025/04/30 01:35:54 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-sabikek0yata/dst': Waiting for checks to finish 2025/04/30 01:35:54 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-sabikek0yata/dst': Waiting for transfers to finish 2025/04/30 01:35:54 DEBUG : Waiting for deletions to finish 2025/04/30 01:35:54 INFO : There was nothing to transfer sync_test.go:2175: No hash on uploaded file so skipping compare timestamp test 2025/04/30 01:35:55 DEBUG : one: Sizes differ (src 5 vs dst 3) 2025/04/30 01:35:55 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/04/30 01:35:55 DEBUG : one: Destination found in --compare-dest, skipping 2025/04/30 01:35:55 DEBUG : two: Sizes differ (src 5 vs dst 3) 2025/04/30 01:35:55 DEBUG : two: Need to transfer - File not found at Destination 2025/04/30 01:35:55 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-sabikek0yata/dst': Waiting for checks to finish 2025/04/30 01:35:55 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-sabikek0yata/dst': Waiting for transfers to finish 2025/04/30 01:35:56 DEBUG : two: md5 = 9c8b045cd633eb17d4b352dfbb7a3f03 OK 2025/04/30 01:35:56 INFO : two: Copied (new) 2025/04/30 01:35:56 DEBUG : Waiting for deletions to finish 2025/04/30 01:35:59 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k" 2025/04/30 01:35:59 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" 2025/04/30 01:36:00 DEBUG : gveqi14airsml4bgu7krj116o8: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k" 2025/04/30 01:36:00 DEBUG : gveqi14airsml4bgu7krj116o8: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" --- PASS: TestSyncCompareDest (24.46s) === RUN TestSyncMultipleCompareDest run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-sabikek0yata'", Local "Local file system at /tmp/rclone1466900237", Modify Window "1ms" 2025/04/30 01:36:04 DEBUG : pre-dest1/1: md5 = 4d8023f790ed972ede4f04b185dc7153 OK 2025/04/30 01:36:07 DEBUG : pre-dest2/2: md5 = cbf8fa8745b6a690822f0aedbff58bb1 OK 2025/04/30 01:36:07 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-sabikek0yata/dest" 2025/04/30 01:36:08 DEBUG : Creating backend with remote "TestDrive:crypt/pil0n1qm7plo2mg2ir1k4f8njnr2gsmbacqrr6opdumvh038dtog/rg03c1jvnehrrc617i0lnqjddc" 2025/04/30 01:36:09 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-sabikek0yata/pre-dest1" 2025/04/30 01:36:09 DEBUG : Creating backend with remote "TestDrive:crypt/pil0n1qm7plo2mg2ir1k4f8njnr2gsmbacqrr6opdumvh038dtog/bbnblvh6k061ssopqrp18kd7gc" 2025/04/30 01:36:10 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-sabikek0yata/pre-dest2" 2025/04/30 01:36:10 DEBUG : Creating backend with remote "TestDrive:crypt/pil0n1qm7plo2mg2ir1k4f8njnr2gsmbacqrr6opdumvh038dtog/dgicm1h6b5ejvlltm8eeif0bnk" 2025/04/30 01:36:12 DEBUG : 1: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/30 01:36:12 DEBUG : 1: Destination found in --compare-dest, skipping 2025/04/30 01:36:12 DEBUG : 2: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/30 01:36:12 DEBUG : 2: Destination found in --compare-dest, skipping 2025/04/30 01:36:13 DEBUG : 3: Need to transfer - File not found at Destination 2025/04/30 01:36:13 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-sabikek0yata/dest': Waiting for checks to finish 2025/04/30 01:36:13 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-sabikek0yata/dest': Waiting for transfers to finish 2025/04/30 01:36:15 DEBUG : 3: md5 = 98c64ff016838b57887aaac1861632ac OK 2025/04/30 01:36:15 INFO : 3: Copied (new) 2025/04/30 01:36:15 DEBUG : Waiting for deletions to finish 2025/04/30 01:36:18 DEBUG : dgicm1h6b5ejvlltm8eeif0bnk: Rmdir: contains trashed file: "1ghu8geql9vrl726n32nrf65bc" 2025/04/30 01:36:18 DEBUG : bbnblvh6k061ssopqrp18kd7gc: Rmdir: contains trashed file: "skbfko3oil7es0lj68ob574sro" 2025/04/30 01:36:19 DEBUG : rg03c1jvnehrrc617i0lnqjddc: Rmdir: contains trashed file: "g072p7hmjchlnj0gibe64c1epg" --- PASS: TestSyncMultipleCompareDest (18.26s) === RUN TestSyncCopyDest run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-sabikek0yata'", Local "Local file system at /tmp/rclone1466900237", Modify Window "1ms" 2025/04/30 01:36:20 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-sabikek0yata/dst" 2025/04/30 01:36:20 DEBUG : Creating backend with remote "TestDrive:crypt/pil0n1qm7plo2mg2ir1k4f8njnr2gsmbacqrr6opdumvh038dtog/31u3jie661vd5p8j7rtc3hgbh0" 2025/04/30 01:36:21 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-sabikek0yata/CopyDest" 2025/04/30 01:36:21 DEBUG : Creating backend with remote "TestDrive:crypt/pil0n1qm7plo2mg2ir1k4f8njnr2gsmbacqrr6opdumvh038dtog/d09o6po3f7bm6ce32vdgs8h9ls" 2025/04/30 01:36:23 DEBUG : one: Need to transfer - File not found at Destination 2025/04/30 01:36:23 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-sabikek0yata/dst': Waiting for checks to finish 2025/04/30 01:36:23 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-sabikek0yata/dst': Waiting for transfers to finish 2025/04/30 01:36:25 DEBUG : one: md5 = d35e38a516a462bd022a272d6f54833c OK 2025/04/30 01:36:25 INFO : one: Copied (new) 2025/04/30 01:36:25 DEBUG : Waiting for deletions to finish 2025/04/30 01:36:26 DEBUG : one: Sizes differ (src 5 vs dst 3) 2025/04/30 01:36:26 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-sabikek0yata/dst': Waiting for checks to finish 2025/04/30 01:36:27 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-sabikek0yata/dst': Waiting for transfers to finish 2025/04/30 01:36:28 DEBUG : one: md5 = e4568eeb07797a3b9c89f85e985ff9f9 OK 2025/04/30 01:36:28 INFO : one: Copied (replaced existing) 2025/04/30 01:36:28 DEBUG : Waiting for deletions to finish 2025/04/30 01:36:30 DEBUG : dst/one: md5 = fa9509052fc1d1004602df9c5eefae7b OK 2025/04/30 01:36:32 DEBUG : CopyDest/one: md5 = 604c7a83b867b8df95ecb1d3d754f6f9 OK 2025/04/30 01:36:33 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-sabikek0yata/BackupDir" 2025/04/30 01:36:33 DEBUG : Creating backend with remote "TestDrive:crypt/pil0n1qm7plo2mg2ir1k4f8njnr2gsmbacqrr6opdumvh038dtog/s6dbk3lfi7c9kfvo6j7bla9m0g" 2025/04/30 01:36:34 DEBUG : one: Sizes differ (src 5 vs dst 3) 2025/04/30 01:36:34 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-sabikek0yata/dst': Waiting for checks to finish 2025/04/30 01:36:35 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/04/30 01:36:35 DEBUG : one: Sizes differ (src 5 vs dst 3) 2025/04/30 01:36:36 INFO : one: Moved (server-side) 2025/04/30 01:36:37 INFO : one: Copied (server-side copy) 2025/04/30 01:36:37 DEBUG : one: Destination found in --copy-dest, using server-side copy 2025/04/30 01:36:37 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-sabikek0yata/dst': Waiting for transfers to finish 2025/04/30 01:36:37 DEBUG : Waiting for deletions to finish 2025/04/30 01:36:52 DEBUG : CopyDest/two: md5 = 8f77595cc10a5402f7d947556aa11e6e OK 2025/04/30 01:36:53 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/04/30 01:36:53 DEBUG : one: Unchanged skipping 2025/04/30 01:36:53 DEBUG : two: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/04/30 01:36:54 INFO : two: Copied (server-side copy) 2025/04/30 01:36:54 DEBUG : two: Destination found in --copy-dest, using server-side copy 2025/04/30 01:36:54 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-sabikek0yata/dst': Waiting for checks to finish 2025/04/30 01:36:54 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-sabikek0yata/dst': Waiting for transfers to finish 2025/04/30 01:36:54 DEBUG : Waiting for deletions to finish 2025/04/30 01:36:55 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/04/30 01:36:55 DEBUG : one: Unchanged skipping 2025/04/30 01:36:55 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-sabikek0yata/dst': Waiting for checks to finish 2025/04/30 01:36:55 DEBUG : two: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/04/30 01:36:55 DEBUG : two: Unchanged skipping 2025/04/30 01:36:55 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-sabikek0yata/dst': Waiting for transfers to finish 2025/04/30 01:36:55 DEBUG : Waiting for deletions to finish 2025/04/30 01:36:55 INFO : There was nothing to transfer 2025/04/30 01:36:57 DEBUG : CopyDest/three: md5 = 2e82f4a4fb3f58c69fb2bfc7d20edca0 OK 2025/04/30 01:36:57 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/04/30 01:36:57 DEBUG : one: Unchanged skipping 2025/04/30 01:36:58 DEBUG : three: Sizes differ (src 7 vs dst 5) 2025/04/30 01:36:58 DEBUG : three: Destination not found in --copy-dest 2025/04/30 01:36:58 DEBUG : three: Need to transfer - File not found at Destination 2025/04/30 01:36:58 DEBUG : two: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/04/30 01:36:58 DEBUG : two: Unchanged skipping 2025/04/30 01:36:58 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-sabikek0yata/dst': Waiting for checks to finish 2025/04/30 01:36:58 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-sabikek0yata/dst': Waiting for transfers to finish 2025/04/30 01:36:59 DEBUG : three: md5 = 3e5fc4a3e990dd4d7d0ceb1d2c8af9fb OK 2025/04/30 01:36:59 INFO : three: Copied (new) 2025/04/30 01:36:59 DEBUG : Waiting for deletions to finish 2025/04/30 01:37:04 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "b6jdmn2b1adrhc8vikh7edr9os" 2025/04/30 01:37:04 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" 2025/04/30 01:37:04 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k" 2025/04/30 01:37:04 DEBUG : d09o6po3f7bm6ce32vdgs8h9ls: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" 2025/04/30 01:37:04 DEBUG : d09o6po3f7bm6ce32vdgs8h9ls: Rmdir: contains trashed file: "b6jdmn2b1adrhc8vikh7edr9os" 2025/04/30 01:37:04 DEBUG : d09o6po3f7bm6ce32vdgs8h9ls: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k" 2025/04/30 01:37:05 DEBUG : s6dbk3lfi7c9kfvo6j7bla9m0g: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" --- PASS: TestSyncCopyDest (45.86s) === RUN TestSyncBackupDir run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-sabikek0yata'", Local "Local file system at /tmp/rclone1466900237", Modify Window "1ms" 2025/04/30 01:37:08 DEBUG : dst/one: md5 = ee0f86f7c60e1e65fbc4ba35d41c9b0e OK 2025/04/30 01:37:09 DEBUG : dst/two: md5 = b0f1955be7c5d65aa0604af781dc69f1 OK 2025/04/30 01:37:11 DEBUG : dst/three.txt: md5 = d84db0e5488ca34d854cd7f3dbd5e18d OK 2025/04/30 01:37:11 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-sabikek0yata/dst" 2025/04/30 01:37:11 DEBUG : Creating backend with remote "TestDrive:crypt/pil0n1qm7plo2mg2ir1k4f8njnr2gsmbacqrr6opdumvh038dtog/31u3jie661vd5p8j7rtc3hgbh0" 2025/04/30 01:37:12 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-sabikek0yata/backup" 2025/04/30 01:37:12 DEBUG : Creating backend with remote "TestDrive:crypt/pil0n1qm7plo2mg2ir1k4f8njnr2gsmbacqrr6opdumvh038dtog/1nrff024r7pq65ecp72fc28jb0" 2025/04/30 01:37:14 DEBUG : one: Sizes differ (src 4 vs dst 3) 2025/04/30 01:37:14 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/30 01:37:14 DEBUG : two: Unchanged skipping 2025/04/30 01:37:14 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-sabikek0yata/dst': Waiting for checks to finish 2025/04/30 01:37:15 INFO : one: Moved (server-side) 2025/04/30 01:37:15 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-sabikek0yata/dst': Waiting for transfers to finish 2025/04/30 01:37:17 DEBUG : one: md5 = 7092e3797ab3a1eeba608d759abc715e OK 2025/04/30 01:37:17 INFO : one: Copied (new) 2025/04/30 01:37:17 DEBUG : Waiting for deletions to finish 2025/04/30 01:37:17 INFO : three.txt: Moved (server-side) 2025/04/30 01:37:17 INFO : three.txt: Moved into backup dir 2025/04/30 01:37:19 DEBUG : dst/three.txt: md5 = 57874ef8aec075aea517ac4143c46090 OK 2025/04/30 01:37:20 DEBUG : one: Sizes differ (src 5 vs dst 4) 2025/04/30 01:37:20 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-sabikek0yata/dst': Waiting for checks to finish 2025/04/30 01:37:20 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/30 01:37:20 DEBUG : two: Unchanged skipping 2025/04/30 01:37:21 INFO : one: Deleted 2025/04/30 01:37:21 INFO : one: Moved (server-side) 2025/04/30 01:37:21 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-sabikek0yata/dst': Waiting for transfers to finish 2025/04/30 01:37:23 DEBUG : one: md5 = c733b2e201f90d2c69256775cd5f0fab OK 2025/04/30 01:37:23 INFO : one: Copied (new) 2025/04/30 01:37:23 DEBUG : Waiting for deletions to finish 2025/04/30 01:37:23 INFO : three.txt: Deleted 2025/04/30 01:37:24 INFO : three.txt: Moved (server-side) 2025/04/30 01:37:24 INFO : three.txt: Moved into backup dir 2025/04/30 01:37:27 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" 2025/04/30 01:37:27 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k" 2025/04/30 01:37:28 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" 2025/04/30 01:37:28 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "tr2hj63d80ftlmvm6a952snjcc" 2025/04/30 01:37:28 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" 2025/04/30 01:37:28 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "tr2hj63d80ftlmvm6a952snjcc" --- PASS: TestSyncBackupDir (22.68s) === RUN TestSyncBackupDirWithSuffix run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-sabikek0yata'", Local "Local file system at /tmp/rclone1466900237", Modify Window "1ms" 2025/04/30 01:37:31 DEBUG : dst/one: md5 = 2132286c3e8d5479c5a76a7ae688b387 OK 2025/04/30 01:37:32 DEBUG : dst/two: md5 = 4bf7cf81d328d0643496e58758d39a68 OK 2025/04/30 01:37:33 DEBUG : dst/three.txt: md5 = 1b20c6b1e81e2ee17861caf583ed112f OK 2025/04/30 01:37:34 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-sabikek0yata/dst" 2025/04/30 01:37:34 DEBUG : Creating backend with remote "TestDrive:crypt/pil0n1qm7plo2mg2ir1k4f8njnr2gsmbacqrr6opdumvh038dtog/31u3jie661vd5p8j7rtc3hgbh0" 2025/04/30 01:37:35 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-sabikek0yata/backup" 2025/04/30 01:37:35 DEBUG : Creating backend with remote "TestDrive:crypt/pil0n1qm7plo2mg2ir1k4f8njnr2gsmbacqrr6opdumvh038dtog/1nrff024r7pq65ecp72fc28jb0" 2025/04/30 01:37:36 DEBUG : one: Sizes differ (src 4 vs dst 3) 2025/04/30 01:37:36 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/30 01:37:36 DEBUG : two: Unchanged skipping 2025/04/30 01:37:36 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-sabikek0yata/dst': Waiting for checks to finish 2025/04/30 01:37:38 INFO : one: Moved (server-side) to: one.bak 2025/04/30 01:37:38 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-sabikek0yata/dst': Waiting for transfers to finish 2025/04/30 01:37:39 DEBUG : one: md5 = a1678ed682765678225d5a45414450cd OK 2025/04/30 01:37:39 INFO : one: Copied (new) 2025/04/30 01:37:39 DEBUG : Waiting for deletions to finish 2025/04/30 01:37:40 INFO : three.txt: Moved (server-side) to: three.txt.bak 2025/04/30 01:37:40 INFO : three.txt: Moved into backup dir 2025/04/30 01:37:42 DEBUG : dst/three.txt: md5 = 29908bbf81f4952c693e2efdf1107f0a OK 2025/04/30 01:37:42 DEBUG : one: Sizes differ (src 5 vs dst 4) 2025/04/30 01:37:42 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/30 01:37:42 DEBUG : two: Unchanged skipping 2025/04/30 01:37:42 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-sabikek0yata/dst': Waiting for checks to finish 2025/04/30 01:37:43 INFO : one.bak: Deleted 2025/04/30 01:37:44 INFO : one: Moved (server-side) to: one.bak 2025/04/30 01:37:44 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-sabikek0yata/dst': Waiting for transfers to finish 2025/04/30 01:37:45 DEBUG : one: md5 = 182d5b66fcfc338e018da92d458c05e5 OK 2025/04/30 01:37:45 INFO : one: Copied (new) 2025/04/30 01:37:45 DEBUG : Waiting for deletions to finish 2025/04/30 01:37:46 INFO : three.txt.bak: Deleted 2025/04/30 01:37:46 INFO : three.txt: Moved (server-side) to: three.txt.bak 2025/04/30 01:37:46 INFO : three.txt: Moved into backup dir 2025/04/30 01:37:49 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" 2025/04/30 01:37:49 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k" 2025/04/30 01:37:50 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "qltcak2uaegtmcoa8vijdppbp8" 2025/04/30 01:37:50 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "sk91qgsqfn0r271r2ehsaoc20c" 2025/04/30 01:37:50 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "qltcak2uaegtmcoa8vijdppbp8" 2025/04/30 01:37:50 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "sk91qgsqfn0r271r2ehsaoc20c" --- PASS: TestSyncBackupDirWithSuffix (22.60s) === RUN TestSyncBackupDirWithSuffixKeepExtension run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-sabikek0yata'", Local "Local file system at /tmp/rclone1466900237", Modify Window "1ms" 2025/04/30 01:37:53 DEBUG : dst/one: md5 = a374ac9fb4e3823917a761031d04ccf0 OK 2025/04/30 01:37:54 DEBUG : dst/two: md5 = f28ca2e86de4c25a46e490ccc5fd2124 OK 2025/04/30 01:37:56 DEBUG : dst/three.txt: md5 = c07dc6f32e18ea43cd2553e40fc492de OK 2025/04/30 01:37:56 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-sabikek0yata/dst" 2025/04/30 01:37:56 DEBUG : Creating backend with remote "TestDrive:crypt/pil0n1qm7plo2mg2ir1k4f8njnr2gsmbacqrr6opdumvh038dtog/31u3jie661vd5p8j7rtc3hgbh0" 2025/04/30 01:37:57 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-sabikek0yata/backup" 2025/04/30 01:37:57 DEBUG : Creating backend with remote "TestDrive:crypt/pil0n1qm7plo2mg2ir1k4f8njnr2gsmbacqrr6opdumvh038dtog/1nrff024r7pq65ecp72fc28jb0" 2025/04/30 01:37:59 DEBUG : one: Sizes differ (src 4 vs dst 3) 2025/04/30 01:37:59 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/30 01:37:59 DEBUG : two: Unchanged skipping 2025/04/30 01:37:59 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-sabikek0yata/dst': Waiting for checks to finish 2025/04/30 01:38:00 INFO : one: Moved (server-side) to: one-2019-01-01 2025/04/30 01:38:00 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-sabikek0yata/dst': Waiting for transfers to finish 2025/04/30 01:38:02 DEBUG : one: md5 = 353cc516c86cea2da6f2de177b73124a OK 2025/04/30 01:38:02 INFO : one: Copied (new) 2025/04/30 01:38:02 DEBUG : Waiting for deletions to finish 2025/04/30 01:38:02 INFO : three.txt: Moved (server-side) to: three-2019-01-01.txt 2025/04/30 01:38:02 INFO : three.txt: Moved into backup dir 2025/04/30 01:38:04 DEBUG : dst/three.txt: md5 = e3498d1fa17b36790468861c04c78201 OK 2025/04/30 01:38:05 DEBUG : one: Sizes differ (src 5 vs dst 4) 2025/04/30 01:38:05 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/30 01:38:05 DEBUG : two: Unchanged skipping 2025/04/30 01:38:05 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-sabikek0yata/dst': Waiting for checks to finish 2025/04/30 01:38:06 INFO : one-2019-01-01: Deleted 2025/04/30 01:38:06 INFO : one: Moved (server-side) to: one-2019-01-01 2025/04/30 01:38:06 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-sabikek0yata/dst': Waiting for transfers to finish 2025/04/30 01:38:08 DEBUG : one: md5 = 93e62855e500c5abc69a11c02f937a58 OK 2025/04/30 01:38:08 INFO : one: Copied (new) 2025/04/30 01:38:08 DEBUG : Waiting for deletions to finish 2025/04/30 01:38:08 INFO : three-2019-01-01.txt: Deleted 2025/04/30 01:38:09 INFO : three.txt: Moved (server-side) to: three-2019-01-01.txt 2025/04/30 01:38:09 INFO : three.txt: Moved into backup dir 2025/04/30 01:38:12 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" 2025/04/30 01:38:12 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k" 2025/04/30 01:38:13 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "jcjl1bv3ep0v8kt35lqql1co90" 2025/04/30 01:38:13 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "qtq2f6qq4lgpsmj88vb7147qje3prudmtfdtr2342fth58vo9a50" 2025/04/30 01:38:13 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "jcjl1bv3ep0v8kt35lqql1co90" 2025/04/30 01:38:13 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "qtq2f6qq4lgpsmj88vb7147qje3prudmtfdtr2342fth58vo9a50" --- PASS: TestSyncBackupDirWithSuffixKeepExtension (22.50s) === RUN TestSyncBackupDirSuffixOnly run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-sabikek0yata'", Local "Local file system at /tmp/rclone1466900237", Modify Window "1ms" 2025/04/30 01:38:16 DEBUG : dst/one: md5 = 7fce323520766038649d1d055de09a6c OK 2025/04/30 01:38:17 DEBUG : dst/two: md5 = f7a2ccfceda1555c6bc274a43107917e OK 2025/04/30 01:38:18 DEBUG : dst/three.txt: md5 = ebd45952ddc9f4cf02494c065f8c7ca8 OK 2025/04/30 01:38:19 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-sabikek0yata/dst" 2025/04/30 01:38:19 DEBUG : Creating backend with remote "TestDrive:crypt/pil0n1qm7plo2mg2ir1k4f8njnr2gsmbacqrr6opdumvh038dtog/31u3jie661vd5p8j7rtc3hgbh0" 2025/04/30 01:38:20 DEBUG : one: Sizes differ (src 4 vs dst 3) 2025/04/30 01:38:20 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/30 01:38:20 DEBUG : two: Unchanged skipping 2025/04/30 01:38:20 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-sabikek0yata/dst': Waiting for checks to finish 2025/04/30 01:38:21 INFO : one: Moved (server-side) to: one.bak 2025/04/30 01:38:21 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-sabikek0yata/dst': Waiting for transfers to finish 2025/04/30 01:38:22 DEBUG : one: md5 = 25fd2073a3bac9b0b8ced8a4a8cb45e8 OK 2025/04/30 01:38:22 INFO : one: Copied (new) 2025/04/30 01:38:22 DEBUG : Waiting for deletions to finish 2025/04/30 01:38:23 INFO : three.txt: Moved (server-side) to: three.txt.bak 2025/04/30 01:38:23 INFO : three.txt: Moved into backup dir 2025/04/30 01:38:25 DEBUG : dst/three.txt: md5 = ce5ed594a889345bc81b8a40ffde6354 OK 2025/04/30 01:38:26 DEBUG : three.txt.bak: Excluded (Path Filter) 2025/04/30 01:38:26 DEBUG : one.bak: Excluded (Path Filter) 2025/04/30 01:38:26 DEBUG : one: Sizes differ (src 5 vs dst 4) 2025/04/30 01:38:26 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/30 01:38:26 DEBUG : two: Unchanged skipping 2025/04/30 01:38:26 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-sabikek0yata/dst': Waiting for checks to finish 2025/04/30 01:38:26 INFO : one.bak: Deleted 2025/04/30 01:38:27 INFO : one: Moved (server-side) to: one.bak 2025/04/30 01:38:27 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-sabikek0yata/dst': Waiting for transfers to finish 2025/04/30 01:38:28 DEBUG : one: md5 = 520cd1d9a185cfceb88a217881c926c1 OK 2025/04/30 01:38:28 INFO : one: Copied (new) 2025/04/30 01:38:28 DEBUG : Waiting for deletions to finish 2025/04/30 01:38:29 INFO : three.txt.bak: Deleted 2025/04/30 01:38:29 INFO : three.txt: Moved (server-side) to: three.txt.bak 2025/04/30 01:38:29 INFO : three.txt: Moved into backup dir 2025/04/30 01:38:33 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" 2025/04/30 01:38:33 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "qltcak2uaegtmcoa8vijdppbp8" 2025/04/30 01:38:33 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "sk91qgsqfn0r271r2ehsaoc20c" 2025/04/30 01:38:33 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "sk91qgsqfn0r271r2ehsaoc20c" 2025/04/30 01:38:33 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "qltcak2uaegtmcoa8vijdppbp8" 2025/04/30 01:38:33 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k" --- PASS: TestSyncBackupDirSuffixOnly (20.74s) === RUN TestSyncSuffix run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-sabikek0yata'", Local "Local file system at /tmp/rclone1466900237", Modify Window "1ms" 2025/04/30 01:38:36 DEBUG : dst/one: md5 = 42150a95eebaf1271b332054e086fb43 OK 2025/04/30 01:38:41 DEBUG : dst/two: md5 = 9d0999a6b427f4e129afb4243a354c90 OK 2025/04/30 01:38:43 DEBUG : dst/three.txt: md5 = f4ecec390f1e95d208b3f12f106b36b3 OK 2025/04/30 01:38:43 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-sabikek0yata/dst" 2025/04/30 01:38:43 DEBUG : Creating backend with remote "TestDrive:crypt/pil0n1qm7plo2mg2ir1k4f8njnr2gsmbacqrr6opdumvh038dtog/31u3jie661vd5p8j7rtc3hgbh0" 2025/04/30 01:38:44 DEBUG : one: Sizes differ (src 4 vs dst 3) 2025/04/30 01:38:45 INFO : one: Moved (server-side) to: one.bak 2025/04/30 01:38:47 DEBUG : one: md5 = 2e14c1175857a91d1bd3a34cc112688c OK 2025/04/30 01:38:47 INFO : one: Copied (new) 2025/04/30 01:38:47 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/30 01:38:47 DEBUG : two: Unchanged skipping 2025/04/30 01:38:47 DEBUG : three.txt: Sizes differ (src 6 vs dst 5) 2025/04/30 01:38:48 INFO : three.txt: Moved (server-side) to: three.txt.bak 2025/04/30 01:38:49 DEBUG : three.txt: md5 = bbbe654b93e15d765329d5f8bc26f342 OK 2025/04/30 01:38:49 INFO : three.txt: Copied (new) 2025/04/30 01:38:51 DEBUG : one: Sizes differ (src 5 vs dst 4) 2025/04/30 01:38:51 INFO : one.bak: Deleted 2025/04/30 01:38:52 INFO : one: Moved (server-side) to: one.bak 2025/04/30 01:38:53 DEBUG : one: md5 = 8b9b3c43ac5e2fa4a8d046133651160e OK 2025/04/30 01:38:53 INFO : one: Copied (new) 2025/04/30 01:38:53 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/30 01:38:53 DEBUG : two: Unchanged skipping 2025/04/30 01:38:53 DEBUG : three.txt: Sizes differ (src 19 vs dst 6) 2025/04/30 01:38:54 INFO : three.txt.bak: Deleted 2025/04/30 01:38:55 INFO : three.txt: Moved (server-side) to: three.txt.bak 2025/04/30 01:38:56 DEBUG : three.txt: md5 = 3c934f0bc86583156e880f01cfc89dd4 OK 2025/04/30 01:38:56 INFO : three.txt: Copied (new) 2025/04/30 01:39:00 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "tr2hj63d80ftlmvm6a952snjcc" 2025/04/30 01:39:00 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" 2025/04/30 01:39:00 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "qltcak2uaegtmcoa8vijdppbp8" 2025/04/30 01:39:00 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "qltcak2uaegtmcoa8vijdppbp8" 2025/04/30 01:39:00 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "sk91qgsqfn0r271r2ehsaoc20c" 2025/04/30 01:39:00 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k" 2025/04/30 01:39:00 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "sk91qgsqfn0r271r2ehsaoc20c" --- PASS: TestSyncSuffix (26.36s) === RUN TestSyncSuffixKeepExtension run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-sabikek0yata'", Local "Local file system at /tmp/rclone1466900237", Modify Window "1ms" 2025/04/30 01:39:02 DEBUG : dst/one: md5 = 4e86cfbd9b707344d0cb596a0f14ec89 OK 2025/04/30 01:39:04 DEBUG : dst/two: md5 = 6ec901026ca53215300549150dce5b55 OK 2025/04/30 01:39:15 DEBUG : dst/three.txt: md5 = e1ae550aa7baa0bd492521cf8a57e955 OK 2025/04/30 01:39:16 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-sabikek0yata/dst" 2025/04/30 01:39:16 DEBUG : Creating backend with remote "TestDrive:crypt/pil0n1qm7plo2mg2ir1k4f8njnr2gsmbacqrr6opdumvh038dtog/31u3jie661vd5p8j7rtc3hgbh0" 2025/04/30 01:39:17 DEBUG : one: Sizes differ (src 4 vs dst 3) 2025/04/30 01:39:17 INFO : one: Moved (server-side) to: one-2019-01-01 2025/04/30 01:39:19 DEBUG : one: md5 = 9ef5d14188e015d19de43d61f604d134 OK 2025/04/30 01:39:19 INFO : one: Copied (new) 2025/04/30 01:39:19 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/30 01:39:19 DEBUG : two: Unchanged skipping 2025/04/30 01:39:19 DEBUG : three.txt: Sizes differ (src 6 vs dst 5) 2025/04/30 01:39:20 INFO : three.txt: Moved (server-side) to: three-2019-01-01.txt 2025/04/30 01:39:22 DEBUG : three.txt: md5 = 92a58613a9cfbe80516ba0292fe6bdb3 OK 2025/04/30 01:39:22 INFO : three.txt: Copied (new) 2025/04/30 01:39:23 DEBUG : one: Sizes differ (src 5 vs dst 4) 2025/04/30 01:39:24 INFO : one-2019-01-01: Deleted 2025/04/30 01:39:24 INFO : one: Moved (server-side) to: one-2019-01-01 2025/04/30 01:39:25 DEBUG : one: md5 = e3afa25e9f259e14400ebcfceeec8e8b OK 2025/04/30 01:39:25 INFO : one: Copied (new) 2025/04/30 01:39:26 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/30 01:39:26 DEBUG : two: Unchanged skipping 2025/04/30 01:39:26 DEBUG : three.txt: Sizes differ (src 19 vs dst 6) 2025/04/30 01:39:27 INFO : three-2019-01-01.txt: Deleted 2025/04/30 01:39:27 INFO : three.txt: Moved (server-side) to: three-2019-01-01.txt 2025/04/30 01:39:29 DEBUG : three.txt: md5 = 44be5a6720d85fe3857f9c8fa8aea330 OK 2025/04/30 01:39:29 INFO : three.txt: Copied (new) 2025/04/30 01:39:32 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" 2025/04/30 01:39:32 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "tr2hj63d80ftlmvm6a952snjcc" 2025/04/30 01:39:32 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "jcjl1bv3ep0v8kt35lqql1co90" 2025/04/30 01:39:32 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "qtq2f6qq4lgpsmj88vb7147qje3prudmtfdtr2342fth58vo9a50" 2025/04/30 01:39:32 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k" 2025/04/30 01:39:32 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "jcjl1bv3ep0v8kt35lqql1co90" 2025/04/30 01:39:32 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "qtq2f6qq4lgpsmj88vb7147qje3prudmtfdtr2342fth58vo9a50" --- PASS: TestSyncSuffixKeepExtension (32.57s) === RUN TestSyncUTFNorm run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-sabikek0yata'", Local "Local file system at /tmp/rclone1466900237", Modify Window "1ms" 2025/04/30 01:39:34 DEBUG : Testêé: md5 = e4c39083719df9552b5c10b5eb769d60 OK 2025/04/30 01:39:35 DEBUG : Testêé: Sizes differ (src 14 vs dst 18) 2025/04/30 01:39:35 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-sabikek0yata': Waiting for checks to finish 2025/04/30 01:39:35 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-sabikek0yata': Waiting for transfers to finish 2025/04/30 01:39:36 DEBUG : Testêé: md5 = 7c2326ba6015e8b2b74fa3c69f14b10a OK 2025/04/30 01:39:36 INFO : Testêé: Copied (replaced existing) to: Testêé 2025/04/30 01:39:36 DEBUG : Waiting for deletions to finish --- PASS: TestSyncUTFNorm (4.30s) === RUN TestSyncImmutable run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-sabikek0yata'", Local "Local file system at /tmp/rclone1466900237", Modify Window "1ms" 2025/04/30 01:39:38 DEBUG : existing: Need to transfer - File not found at Destination 2025/04/30 01:39:38 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-sabikek0yata': Waiting for checks to finish 2025/04/30 01:39:38 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-sabikek0yata': Waiting for transfers to finish 2025/04/30 01:39:39 DEBUG : existing: md5 = 5207ef0e77c2e3b95401b40983b699cb OK 2025/04/30 01:39:39 INFO : existing: Copied (new) 2025/04/30 01:39:39 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-sabikek0yata'", Local "Local file system at /tmp/rclone1466900237", Modify Window "1ms" 2025/04/30 01:39:40 DEBUG : existing: Sizes differ (src 8 vs dst 6) 2025/04/30 01:39:40 ERROR : existing: Source and destination exist but do not match: immutable file modified 2025/04/30 01:39:40 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-sabikek0yata': Waiting for checks to finish 2025/04/30 01:39:40 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-sabikek0yata': Waiting for transfers to finish 2025/04/30 01:39:40 ERROR : Encrypted drive 'TestCryptDrive:rclone-test-sabikek0yata': not deleting files as there were IO errors 2025/04/30 01:39:40 ERROR : Encrypted drive 'TestCryptDrive:rclone-test-sabikek0yata': not deleting directories as there were IO errors run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-sabikek0yata'", Local "Local file system at /tmp/rclone1466900237", Modify Window "1ms" --- PASS: TestSyncImmutable (4.51s) === RUN TestSyncIgnoreCase run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-sabikek0yata'", Local "Local file system at /tmp/rclone1466900237", Modify Window "1ms" 2025/04/30 01:39:43 DEBUG : EXISTING: md5 = 3efe1eb5b36753c3c1fa5000f75ea13b OK 2025/04/30 01:39:44 DEBUG : existing: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/30 01:39:44 DEBUG : existing: Unchanged skipping 2025/04/30 01:39:44 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-sabikek0yata': Waiting for checks to finish 2025/04/30 01:39:44 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-sabikek0yata': Waiting for transfers to finish 2025/04/30 01:39:44 DEBUG : Waiting for deletions to finish 2025/04/30 01:39:44 INFO : There was nothing to transfer --- PASS: TestSyncIgnoreCase (3.16s) === RUN TestFixCase run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-sabikek0yata'", Local "Local file system at /tmp/rclone1466900237", Modify Window "1ms" sync_test.go:2635: Skipping test as local or remote are case-sensitive --- SKIP: TestFixCase (0.43s) === RUN TestMaxTransfer === RUN TestMaxTransfer/Hard run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-sabikek0yata'", Local "Local file system at /tmp/rclone1466900237", 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-sabikek0yata'", Local "Local file system at /tmp/rclone1466900237", 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-sabikek0yata'", Local "Local file system at /tmp/rclone1466900237", Modify Window "1ms" sync_test.go:2674: This test only runs on local --- PASS: TestMaxTransfer (1.39s) --- SKIP: TestMaxTransfer/Hard (0.43s) --- SKIP: TestMaxTransfer/Soft (0.53s) --- SKIP: TestMaxTransfer/Cautious (0.43s) === RUN TestSyncConcurrentDelete run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-sabikek0yata'", Local "Local file system at /tmp/rclone1466900237", Modify Window "1ms" 2025/04/30 01:39:48 DEBUG : both0: md5 = 3db400dd296aec5cdf2cf5021f83697c OK 2025/04/30 01:39:50 DEBUG : only0: md5 = d62c70538a109fe8df567a625ffa1e79 OK 2025/04/30 01:39:51 DEBUG : both1: md5 = 693c36b24323b274f897597fd5799801 OK 2025/04/30 01:39:53 DEBUG : only1: md5 = b4976e6f2b7466efc23bf87efd447bec OK 2025/04/30 01:39:54 DEBUG : both2: md5 = b90e2398200b0240e5e0e0106a57dbff OK 2025/04/30 01:39:55 DEBUG : only2: md5 = 0400baa9b15bfb9c35b30a508f01e895 OK 2025/04/30 01:39:57 DEBUG : both3: md5 = 661b856b4f92ec047ecb4fa24f8c6a9b OK 2025/04/30 01:39:58 DEBUG : only3: md5 = 849f1b56e8f90c4556ca487cf3195a91 OK 2025/04/30 01:39:59 DEBUG : both4: md5 = c6de2ed2fa96a9e4a89703ddc46a1d2b OK 2025/04/30 01:40:01 DEBUG : only4: md5 = 38f173b265662017db9255aff4ae870c OK 2025/04/30 01:40:03 DEBUG : both5: md5 = e949f668aa1820d90b2471b83adb60a9 OK 2025/04/30 01:40:04 DEBUG : only5: md5 = a03e3185ecf812d07eddb9e5a3d1ddc4 OK 2025/04/30 01:40:05 DEBUG : both6: md5 = 0fff49656102457a5ff4f78cb2101a1d OK 2025/04/30 01:40:07 DEBUG : only6: md5 = d1b6f1e02c5c20254072921823a9a284 OK 2025/04/30 01:40:08 DEBUG : both7: md5 = 1fa94bb85059fde514e991fef3f3dd65 OK 2025/04/30 01:40:09 DEBUG : only7: md5 = 5cdc95ec53dfe56a9cb8df78ace469ec OK 2025/04/30 01:40:11 DEBUG : both8: md5 = 5bb768185a13973f37682f744bd27a27 OK 2025/04/30 01:40:12 DEBUG : only8: md5 = 00cb08595c6bf3aa3e2a9ae1ee2e6f05 OK 2025/04/30 01:40:14 DEBUG : both9: md5 = 653ad9d34bb945e708a050457bf9ac4f OK 2025/04/30 01:40:15 DEBUG : only9: md5 = b9c9d2868e554701d49460c8fae30dc5 OK 2025/04/30 01:40:17 DEBUG : both10: md5 = 2e2a446bb63739004327597063ff67f4 OK 2025/04/30 01:40:18 DEBUG : only10: md5 = e6b3cbc3dba2ed1a8b3273eeafce628d OK 2025/04/30 01:40:20 DEBUG : both11: md5 = 5dfe75517692b657840fab8969c1c638 OK 2025/04/30 01:40:21 DEBUG : only11: md5 = 60326bf79bfa89b95e1c6718fce78925 OK 2025/04/30 01:40:22 DEBUG : both12: md5 = 23cb37ca00353fa532147bfe95ac724e OK 2025/04/30 01:40:24 DEBUG : only12: md5 = 432007b924d56ccfc666770a7361ae5e OK 2025/04/30 01:40:25 DEBUG : both13: md5 = 47bdf0cfe7e36b2903c430c0ff8f1c8a OK 2025/04/30 01:40:26 DEBUG : only13: md5 = 9db7eca9d8137a7edb2990a290f3c383 OK 2025/04/30 01:40:28 DEBUG : both14: md5 = e2cfb47e17247f52629ea901d4db2651 OK 2025/04/30 01:40:29 DEBUG : only14: md5 = 756beaf375363deea4a00e618609604a OK 2025/04/30 01:40:30 DEBUG : both15: md5 = d54da0053af5ce5d775c4fe66597c371 OK 2025/04/30 01:40:32 DEBUG : only15: md5 = 6ca57cefd047c1abb14b73cbbad1774c OK 2025/04/30 01:40:33 DEBUG : both16: md5 = 60d262da7cd9a43e95d1886ae80a36c1 OK 2025/04/30 01:40:34 DEBUG : only16: md5 = 20d1360dd77c7404c8dabe13223e1ef6 OK 2025/04/30 01:40:36 DEBUG : both17: md5 = 13c52675ec8ba11ad36ee44e098e5c13 OK 2025/04/30 01:40:37 DEBUG : only17: md5 = 4192535d71e681723a35ba404badf168 OK 2025/04/30 01:40:38 DEBUG : both18: md5 = c723daffde91cc7495aff8728122ab50 OK 2025/04/30 01:40:40 DEBUG : only18: md5 = 6434ff233e145393f631f2b9aa6968f0 OK 2025/04/30 01:40:41 DEBUG : both19: md5 = 71ee1f20b4e7536bd65cad73d8b88697 OK 2025/04/30 01:40:43 DEBUG : only19: md5 = 7873c3398f3bacbad6dba5a9f6952623 OK 2025/04/30 01:40:43 DEBUG : both1: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/30 01:40:43 DEBUG : both10: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/30 01:40:43 DEBUG : both0: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/30 01:40:43 DEBUG : both11: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/30 01:40:43 DEBUG : both1: Unchanged skipping 2025/04/30 01:40:43 DEBUG : both12: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/30 01:40:43 DEBUG : both10: Unchanged skipping 2025/04/30 01:40:43 DEBUG : both13: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/30 01:40:43 DEBUG : both13: Unchanged skipping 2025/04/30 01:40:43 DEBUG : both14: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/30 01:40:43 DEBUG : both14: Unchanged skipping 2025/04/30 01:40:43 DEBUG : both15: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/30 01:40:43 DEBUG : both15: Unchanged skipping 2025/04/30 01:40:43 DEBUG : both16: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/30 01:40:43 DEBUG : both16: Unchanged skipping 2025/04/30 01:40:43 DEBUG : both17: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/30 01:40:43 DEBUG : both17: Unchanged skipping 2025/04/30 01:40:43 DEBUG : both18: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/30 01:40:43 DEBUG : both18: Unchanged skipping 2025/04/30 01:40:43 DEBUG : both19: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/30 01:40:43 DEBUG : both19: Unchanged skipping 2025/04/30 01:40:43 DEBUG : both2: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/30 01:40:43 DEBUG : both2: Unchanged skipping 2025/04/30 01:40:43 DEBUG : both3: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/30 01:40:43 DEBUG : both3: Unchanged skipping 2025/04/30 01:40:43 DEBUG : both4: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/30 01:40:43 DEBUG : both4: Unchanged skipping 2025/04/30 01:40:43 DEBUG : both5: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/30 01:40:43 DEBUG : both5: Unchanged skipping 2025/04/30 01:40:43 DEBUG : both6: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/30 01:40:43 DEBUG : both6: Unchanged skipping 2025/04/30 01:40:43 DEBUG : both7: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/30 01:40:43 DEBUG : both7: Unchanged skipping 2025/04/30 01:40:43 DEBUG : both8: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/30 01:40:43 DEBUG : both8: Unchanged skipping 2025/04/30 01:40:43 DEBUG : both9: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/30 01:40:43 DEBUG : both9: Unchanged skipping 2025/04/30 01:40:43 DEBUG : both0: Unchanged skipping 2025/04/30 01:40:43 DEBUG : both11: Unchanged skipping 2025/04/30 01:40:43 DEBUG : both12: Unchanged skipping 2025/04/30 01:40:43 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-sabikek0yata': Waiting for checks to finish 2025/04/30 01:40:43 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-sabikek0yata': Waiting for transfers to finish 2025/04/30 01:40:43 DEBUG : Waiting for deletions to finish 2025/04/30 01:40:43 INFO : only16: Deleted 2025/04/30 01:40:44 INFO : only8: Deleted 2025/04/30 01:40:44 INFO : only9: Deleted 2025/04/30 01:40:44 INFO : only1: Deleted 2025/04/30 01:40:44 INFO : only17: Deleted 2025/04/30 01:40:44 INFO : only6: Deleted 2025/04/30 01:40:44 INFO : only7: Deleted 2025/04/30 01:40:44 INFO : only3: Deleted 2025/04/30 01:40:44 INFO : only4: Deleted 2025/04/30 01:40:44 INFO : only10: Deleted 2025/04/30 01:40:44 INFO : only18: Deleted 2025/04/30 01:40:44 INFO : only0: Deleted 2025/04/30 01:40:45 INFO : only11: Deleted 2025/04/30 01:40:45 INFO : only12: Deleted 2025/04/30 01:40:45 INFO : only13: Deleted 2025/04/30 01:40:45 INFO : only15: Deleted 2025/04/30 01:40:45 INFO : only14: Deleted 2025/04/30 01:40:46 INFO : only2: Deleted 2025/04/30 01:40:46 INFO : only5: Deleted 2025/04/30 01:40:46 INFO : only19: Deleted 2025/04/30 01:40:46 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-sabikek0yata'", Local "Local file system at /tmp/rclone1466900237", Modify Window "1ms" --- PASS: TestSyncConcurrentDelete (69.50s) === RUN TestSyncConcurrentTruncate run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-sabikek0yata'", Local "Local file system at /tmp/rclone1466900237", Modify Window "1ms" 2025/04/30 01:40:58 DEBUG : both0: md5 = f1fda59c207c94b6a7955abcd9605cb5 OK 2025/04/30 01:40:59 DEBUG : only0: md5 = 2c7cddea00441455552d8e4ba87c3eb1 OK 2025/04/30 01:41:00 DEBUG : both1: md5 = 4a4a657b4e469bfd9ae8ea5e3e1a371d OK 2025/04/30 01:41:02 DEBUG : only1: md5 = 776066fc46f746fe444c12d41bf98636 OK 2025/04/30 01:41:03 DEBUG : both2: md5 = cd39a6edda77d9fa1ae014d02c45ebae OK 2025/04/30 01:41:05 DEBUG : only2: md5 = dcd65e06528b434c43b719e453507803 OK 2025/04/30 01:41:06 DEBUG : both3: md5 = b00de785b06b56d1be8f7ca3f8638f99 OK 2025/04/30 01:41:07 DEBUG : only3: md5 = ff3dbd628b3b511870fb2521c7f2de96 OK 2025/04/30 01:41:09 DEBUG : both4: md5 = 6fac9496efa129c76c95ed9574ca2b1a OK 2025/04/30 01:41:10 DEBUG : only4: md5 = 4e3eec1acc3a9c3147c552057cacc5ab OK 2025/04/30 01:41:12 DEBUG : both5: md5 = efbb76bc896671bc2d716451ba2ca455 OK 2025/04/30 01:41:13 DEBUG : only5: md5 = ed9908edb7b7abbb98de28eeb54a7473 OK 2025/04/30 01:41:15 DEBUG : both6: md5 = 94c62f46d64691fc239897bb651618db OK 2025/04/30 01:41:16 DEBUG : only6: md5 = 61fd4cc59dfc1cab6f76ebe81815f3d8 OK 2025/04/30 01:41:18 DEBUG : both7: md5 = 15aaaa543460daa4153110aa67d838e0 OK 2025/04/30 01:41:19 DEBUG : only7: md5 = 77572ca92c8090d382adb0af18160db8 OK 2025/04/30 01:41:21 DEBUG : both8: md5 = e3bb1d528af1e914169c81e69ebe5c20 OK 2025/04/30 01:41:22 DEBUG : only8: md5 = c176b6d5f43778a7886c266103f3e8e0 OK 2025/04/30 01:41:23 DEBUG : both9: md5 = 903a01803fd7c66cc0952c1aea1bd2cf OK 2025/04/30 01:41:25 DEBUG : only9: md5 = 9ad60ce77720c9ea019f6b249c05705b OK 2025/04/30 01:41:26 DEBUG : both10: md5 = f8685c8ccd42b44c5792587838763276 OK 2025/04/30 01:41:28 DEBUG : only10: md5 = ed4c84de86fae9f3946b4983935dde44 OK 2025/04/30 01:41:29 DEBUG : both11: md5 = f55bdc1b2e19868913a4d917a8e6a96c OK 2025/04/30 01:41:30 DEBUG : only11: md5 = f2bb848b137c599bc669d9f0c05838c1 OK 2025/04/30 01:41:32 DEBUG : both12: md5 = be124bfbe0fa4a6e87b670bc2c34b84c OK 2025/04/30 01:41:33 DEBUG : only12: md5 = b70510da80408e8c77ee5f7367481415 OK 2025/04/30 01:41:34 DEBUG : both13: md5 = dece9ae1302d208849a079a47a02e2f3 OK 2025/04/30 01:41:36 DEBUG : only13: md5 = eb02740da4a88805480eeafe149478c2 OK 2025/04/30 01:41:37 DEBUG : both14: md5 = ae056cd1ee4527e1c208c6e92454ae57 OK 2025/04/30 01:41:38 DEBUG : only14: md5 = d4cf891d759203684066352c7559b091 OK 2025/04/30 01:41:40 DEBUG : both15: md5 = a60d43f88a52ee9a1e2cd44d8a65e7c2 OK 2025/04/30 01:41:41 DEBUG : only15: md5 = 5c13e0b0f52e2f3ae451dfdf87538220 OK 2025/04/30 01:41:43 DEBUG : both16: md5 = 5323c873e73e4feaed02c90dd57cf9c9 OK 2025/04/30 01:41:44 DEBUG : only16: md5 = 41d8af8bc824541a1dc184cf4168e008 OK 2025/04/30 01:41:46 DEBUG : both17: md5 = 3aacfcc9d195d08a0bc62c73009cc878 OK 2025/04/30 01:41:47 DEBUG : only17: md5 = 9da0c037771286c1b19a54584bfd0a24 OK 2025/04/30 01:41:48 DEBUG : both18: md5 = 17c2ca66c1d58fdef0b9d1d07dbfb7a1 OK 2025/04/30 01:41:50 DEBUG : only18: md5 = d519252e0570fac055beaf9aa46e9b33 OK 2025/04/30 01:41:51 DEBUG : both19: md5 = c6e0eac3629ce3761f17d896591bf41f OK 2025/04/30 01:41:52 DEBUG : only19: md5 = bddb764bbc9235c72edcea7ff28f7473 OK 2025/04/30 01:41:53 DEBUG : both0: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/30 01:41:53 DEBUG : both0: Unchanged skipping 2025/04/30 01:41:53 DEBUG : both1: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/30 01:41:53 DEBUG : both1: Unchanged skipping 2025/04/30 01:41:53 DEBUG : both10: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/30 01:41:53 DEBUG : both10: Unchanged skipping 2025/04/30 01:41:53 DEBUG : both11: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/30 01:41:53 DEBUG : both11: Unchanged skipping 2025/04/30 01:41:53 DEBUG : both12: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/30 01:41:53 DEBUG : both12: Unchanged skipping 2025/04/30 01:41:53 DEBUG : both13: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/30 01:41:53 DEBUG : both13: Unchanged skipping 2025/04/30 01:41:53 DEBUG : both14: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/30 01:41:53 DEBUG : both14: Unchanged skipping 2025/04/30 01:41:53 DEBUG : both15: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/30 01:41:53 DEBUG : both15: Unchanged skipping 2025/04/30 01:41:53 DEBUG : both16: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/30 01:41:53 DEBUG : both16: Unchanged skipping 2025/04/30 01:41:53 DEBUG : both17: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/30 01:41:53 DEBUG : both17: Unchanged skipping 2025/04/30 01:41:53 DEBUG : both18: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/30 01:41:53 DEBUG : both18: Unchanged skipping 2025/04/30 01:41:53 DEBUG : both19: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/30 01:41:53 DEBUG : both19: Unchanged skipping 2025/04/30 01:41:53 DEBUG : both2: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/30 01:41:53 DEBUG : both2: Unchanged skipping 2025/04/30 01:41:53 DEBUG : both3: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/30 01:41:53 DEBUG : both3: Unchanged skipping 2025/04/30 01:41:53 DEBUG : both4: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/30 01:41:53 DEBUG : both4: Unchanged skipping 2025/04/30 01:41:53 DEBUG : both5: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/30 01:41:53 DEBUG : both5: Unchanged skipping 2025/04/30 01:41:53 DEBUG : both6: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/30 01:41:53 DEBUG : both6: Unchanged skipping 2025/04/30 01:41:53 DEBUG : both7: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/30 01:41:53 DEBUG : both7: Unchanged skipping 2025/04/30 01:41:53 DEBUG : both8: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/30 01:41:53 DEBUG : both8: Unchanged skipping 2025/04/30 01:41:53 DEBUG : both9: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/30 01:41:53 DEBUG : both9: Unchanged skipping 2025/04/30 01:41:53 DEBUG : only0: Sizes differ (src 0 vs dst 6) 2025/04/30 01:41:53 DEBUG : only1: Sizes differ (src 0 vs dst 6) 2025/04/30 01:41:53 DEBUG : only10: Sizes differ (src 0 vs dst 6) 2025/04/30 01:41:53 DEBUG : only11: Sizes differ (src 0 vs dst 6) 2025/04/30 01:41:53 DEBUG : only12: Sizes differ (src 0 vs dst 6) 2025/04/30 01:41:53 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-sabikek0yata': Waiting for checks to finish 2025/04/30 01:41:53 DEBUG : only13: Sizes differ (src 0 vs dst 6) 2025/04/30 01:41:53 DEBUG : only14: Sizes differ (src 0 vs dst 6) 2025/04/30 01:41:53 DEBUG : only15: Sizes differ (src 0 vs dst 6) 2025/04/30 01:41:53 DEBUG : only16: Sizes differ (src 0 vs dst 6) 2025/04/30 01:41:53 DEBUG : only17: Sizes differ (src 0 vs dst 6) 2025/04/30 01:41:53 DEBUG : only18: Sizes differ (src 0 vs dst 6) 2025/04/30 01:41:53 DEBUG : only19: Sizes differ (src 0 vs dst 6) 2025/04/30 01:41:53 DEBUG : only2: Sizes differ (src 0 vs dst 6) 2025/04/30 01:41:53 DEBUG : only3: Sizes differ (src 0 vs dst 6) 2025/04/30 01:41:53 DEBUG : only4: Sizes differ (src 0 vs dst 6) 2025/04/30 01:41:53 DEBUG : only5: Sizes differ (src 0 vs dst 6) 2025/04/30 01:41:53 DEBUG : only6: Sizes differ (src 0 vs dst 6) 2025/04/30 01:41:53 DEBUG : only7: Sizes differ (src 0 vs dst 6) 2025/04/30 01:41:53 DEBUG : only8: Sizes differ (src 0 vs dst 6) 2025/04/30 01:41:53 DEBUG : only9: Sizes differ (src 0 vs dst 6) 2025/04/30 01:41:53 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-sabikek0yata': Waiting for transfers to finish 2025/04/30 01:41:54 DEBUG : only0: md5 = 05a8a5a22d408a308c816dd89741db3b OK 2025/04/30 01:41:54 INFO : only0: Copied (replaced existing) 2025/04/30 01:41:54 DEBUG : only10: md5 = b1e7e05521204ae1908be1b48a9d936b OK 2025/04/30 01:41:54 INFO : only10: Copied (replaced existing) 2025/04/30 01:41:54 DEBUG : only1: md5 = 9130080b59d6fa1efba345273c2bd0b9 OK 2025/04/30 01:41:54 INFO : only1: Copied (replaced existing) 2025/04/30 01:41:54 DEBUG : only13: md5 = 13a181bbe5268272092c53ca208cb3f0 OK 2025/04/30 01:41:54 INFO : only13: Copied (replaced existing) 2025/04/30 01:41:55 DEBUG : only15: md5 = c989f9b8a83dbb48f8e7fefe79ec66b4 OK 2025/04/30 01:41:55 INFO : only15: Copied (replaced existing) 2025/04/30 01:41:55 DEBUG : only16: md5 = b3feb189527e4d47c85d5837793351bc OK 2025/04/30 01:41:55 INFO : only16: Copied (replaced existing) 2025/04/30 01:41:55 DEBUG : only17: md5 = 2ef5338749034b46093e082c1fe40ad4 OK 2025/04/30 01:41:55 INFO : only17: Copied (replaced existing) 2025/04/30 01:41:56 DEBUG : only18: md5 = f91425e4020f9c718189fbcf18a52713 OK 2025/04/30 01:41:56 INFO : only18: Copied (replaced existing) 2025/04/30 01:41:56 DEBUG : only19: md5 = 04b44c7ff88591cc265adc44954ee54d OK 2025/04/30 01:41:56 INFO : only19: Copied (replaced existing) 2025/04/30 01:41:57 DEBUG : only2: md5 = 9e70a6fcea8887fe863e0b0504b0e541 OK 2025/04/30 01:41:57 INFO : only2: Copied (replaced existing) 2025/04/30 01:41:57 DEBUG : only3: md5 = ce18eb542c3b14bfd0a1e06465e1d074 OK 2025/04/30 01:41:57 INFO : only3: Copied (replaced existing) 2025/04/30 01:41:57 DEBUG : only4: md5 = 210cb7822dbc4e496d1ea75adf89551e OK 2025/04/30 01:41:57 INFO : only4: Copied (replaced existing) 2025/04/30 01:41:58 DEBUG : only6: md5 = e1d135a727ac407b9490766ee59e1d1e OK 2025/04/30 01:41:58 INFO : only6: Copied (replaced existing) 2025/04/30 01:41:58 DEBUG : only5: md5 = 088029146ab7e4eb1505e8ee056e7493 OK 2025/04/30 01:41:58 INFO : only5: Copied (replaced existing) 2025/04/30 01:41:58 DEBUG : only8: md5 = 970cc372b8bbfa361be1782259f98d3b OK 2025/04/30 01:41:58 INFO : only8: Copied (replaced existing) 2025/04/30 01:41:58 DEBUG : only7: md5 = c7384c38272c1194841672d3e4c757ac OK 2025/04/30 01:41:58 INFO : only7: Copied (replaced existing) 2025/04/30 01:41:59 DEBUG : only11: md5 = 7808c76f0f2ee4e09639560fdd671571 OK 2025/04/30 01:41:59 INFO : only11: Copied (replaced existing) 2025/04/30 01:41:59 DEBUG : only9: md5 = ec5939dd0a935e57c2998a9089c76cc3 OK 2025/04/30 01:41:59 INFO : only9: Copied (replaced existing) 2025/04/30 01:41:59 DEBUG : only12: md5 = c0ea65dbbf68dda2a56518651ba3e1f5 OK 2025/04/30 01:41:59 INFO : only12: Copied (replaced existing) 2025/04/30 01:41:59 DEBUG : only14: md5 = 9ac7a5e9747834fd4a1db2e0978ba034 OK 2025/04/30 01:41:59 INFO : only14: Copied (replaced existing) 2025/04/30 01:41:59 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-sabikek0yata'", Local "Local file system at /tmp/rclone1466900237", Modify Window "1ms" --- PASS: TestSyncConcurrentTruncate (83.61s) === RUN TestSyncReplaceDirModTime run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-sabikek0yata'", Local "Local file system at /tmp/rclone1466900237", Modify Window "1ms" 2025/04/30 01:42:20 DEBUG : empty_dir: Making directory with metadata 2025/04/30 01:42:20 INFO : empty_dir: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2025/04/30 01:42:20 DEBUG : empty_on_remote: Making directory with metadata 2025/04/30 01:42:20 INFO : empty_on_remote: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2025/04/30 01:42:20 DEBUG : empty_on_remote: Making directory with metadata 2025/04/30 01:42:21 INFO : empty_on_remote: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-sabikek0yata'", Local "Local file system at /tmp/rclone1466900237", Modify Window "1ms" 2025/04/30 01:42:26 INFO : test_dir1: Set directory modification time (using DirSetModTime) 2025/04/30 01:42:26 INFO : test_dir2: Set directory modification time (using DirSetModTime) 2025/04/30 01:42:26 INFO : test_dir2/sub_dir: Set directory modification time (using DirSetModTime) 2025/04/30 01:42:26 INFO : empty_on_remote: Set directory modification time (using DirSetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-sabikek0yata'", Local "Local file system at /tmp/rclone1466900237", Modify Window "1ms" 2025/04/30 01:42:33 DEBUG : heqj02jg0dcqlem7gl0500bvp0/24g2k8bseitblkmqnie1ibl2s8: Rmdir: contains trashed file: "633fmaa0qic3kv3cladnu11pto" 2025/04/30 01:42:34 DEBUG : heqj02jg0dcqlem7gl0500bvp0: Rmdir: contains trashed file: "24g2k8bseitblkmqnie1ibl2s8" 2025/04/30 01:42:35 DEBUG : gq68srrpl0nnf394bgf7dbu9kc: Rmdir: contains trashed file: "d26uovf0miqhd1mu3c9jbseq00" --- PASS: TestSyncReplaceDirModTime (17.14s) === RUN TestSyncReplaceDirModTimeWithEmptyDirs run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-sabikek0yata'", Local "Local file system at /tmp/rclone1466900237", Modify Window "1ms" 2025/04/30 01:42:37 DEBUG : empty_dir: Making directory with metadata 2025/04/30 01:42:37 INFO : empty_dir: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2025/04/30 01:42:37 DEBUG : empty_on_remote: Making directory with metadata 2025/04/30 01:42:37 INFO : empty_on_remote: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2025/04/30 01:42:37 DEBUG : empty_on_remote: Making directory with metadata 2025/04/30 01:42:38 INFO : empty_on_remote: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-sabikek0yata'", Local "Local file system at /tmp/rclone1466900237", Modify Window "1ms" 2025/04/30 01:42:43 INFO : test_dir1: Set directory modification time (using DirSetModTime) 2025/04/30 01:42:43 INFO : test_dir2: Set directory modification time (using DirSetModTime) 2025/04/30 01:42:43 INFO : test_dir2/sub_dir: Set directory modification time (using DirSetModTime) 2025/04/30 01:42:43 INFO : empty_on_remote: Set directory modification time (using DirSetModTime) 2025/04/30 01:42:43 INFO : empty_dir: Set directory modification time (using DirSetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-sabikek0yata'", Local "Local file system at /tmp/rclone1466900237", Modify Window "1ms" 2025/04/30 01:42:51 DEBUG : heqj02jg0dcqlem7gl0500bvp0/24g2k8bseitblkmqnie1ibl2s8: Rmdir: contains trashed file: "633fmaa0qic3kv3cladnu11pto" 2025/04/30 01:42:51 DEBUG : heqj02jg0dcqlem7gl0500bvp0: Rmdir: contains trashed file: "24g2k8bseitblkmqnie1ibl2s8" 2025/04/30 01:42:52 DEBUG : gq68srrpl0nnf394bgf7dbu9kc: Rmdir: contains trashed file: "d26uovf0miqhd1mu3c9jbseq00" --- PASS: TestSyncReplaceDirModTimeWithEmptyDirs (17.78s) === RUN TestNothingToTransferWithEmptyDirs run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-sabikek0yata'", Local "Local file system at /tmp/rclone1466900237", Modify Window "1ms" 2025/04/30 01:42:55 INFO : sub dir: Set directory modification time (using DirSetModTime) 2025/04/30 01:42:55 DEBUG : sub dir: Making directory with metadata 2025/04/30 01:42:56 INFO : sub dir: Made directory with metadata (mtime=2011-12-30T12:59:59Z) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-sabikek0yata'", Local "Local file system at /tmp/rclone1466900237", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-sabikek0yata'", Local "Local file system at /tmp/rclone1466900237", Modify Window "1ms" 2025/04/30 01:43:13 INFO : sub dir2: Set directory modification time (using DirSetModTime) 2025/04/30 01:43:14 INFO : sub dir2: Set directory modification time (using DirSetModTime) 2025/04/30 01:43:14 INFO : sub dirEmpty/sub dirEmpty2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2025/04/30 01:43:14 INFO : sub dirEmpty: Set directory modification time (using DirSetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-sabikek0yata'", Local "Local file system at /tmp/rclone1466900237", Modify Window "1ms" 2025/04/30 01:43:28 DEBUG : gcsdkq814sbtppue42dpsbg8ug: Rmdir: contains trashed file: "sjuo65gk5q3r1199jselk9k9o0" 2025/04/30 01:43:29 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/37qp6d1gohacv723ij3brofbu8/i24n0ln37pa2hv8pctddeuh73o: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" 2025/04/30 01:43:29 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/37qp6d1gohacv723ij3brofbu8: Rmdir: contains trashed file: "i24n0ln37pa2hv8pctddeuh73o" 2025/04/30 01:43:30 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "37qp6d1gohacv723ij3brofbu8" 2025/04/30 01:43:31 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak" 2025/04/30 01:43:32 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak" 2025/04/30 01:43:32 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak" 2025/04/30 01:43:33 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak" 2025/04/30 01:43:34 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/4r13oncfa2rsrr82oqhsqv24ns: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" 2025/04/30 01:43:34 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc: Rmdir: contains trashed file: "4r13oncfa2rsrr82oqhsqv24ns" 2025/04/30 01:43:34 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak" 2025/04/30 01:43:35 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestNothingToTransferWithEmptyDirs (42.10s) === RUN TestNothingToTransferWithoutEmptyDirs run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-sabikek0yata'", Local "Local file system at /tmp/rclone1466900237", Modify Window "1ms" 2025/04/30 01:43:37 INFO : sub dir: Set directory modification time (using DirSetModTime) 2025/04/30 01:43:37 DEBUG : sub dir: Making directory with metadata 2025/04/30 01:43:38 INFO : sub dir: Made directory with metadata (mtime=2011-12-30T12:59:59Z) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-sabikek0yata'", Local "Local file system at /tmp/rclone1466900237", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-sabikek0yata'", Local "Local file system at /tmp/rclone1466900237", Modify Window "1ms" 2025/04/30 01:44:00 INFO : sub dir2: Set directory modification time (using DirSetModTime) 2025/04/30 01:44:00 INFO : sub dir2: Set directory modification time (using DirSetModTime) 2025/04/30 01:44:00 INFO : sub dirEmpty/sub dirEmpty2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2025/04/30 01:44:00 INFO : sub dirEmpty: Set directory modification time (using DirSetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-sabikek0yata'", Local "Local file system at /tmp/rclone1466900237", Modify Window "1ms" 2025/04/30 01:44:13 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/37qp6d1gohacv723ij3brofbu8/i24n0ln37pa2hv8pctddeuh73o: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" 2025/04/30 01:44:14 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/37qp6d1gohacv723ij3brofbu8: Rmdir: contains trashed file: "i24n0ln37pa2hv8pctddeuh73o" 2025/04/30 01:44:15 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "37qp6d1gohacv723ij3brofbu8" 2025/04/30 01:44:16 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak" 2025/04/30 01:44:16 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak" 2025/04/30 01:44:17 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak" 2025/04/30 01:44:18 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak" 2025/04/30 01:44:18 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/4r13oncfa2rsrr82oqhsqv24ns: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" 2025/04/30 01:44:19 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc: Rmdir: contains trashed file: "4r13oncfa2rsrr82oqhsqv24ns" 2025/04/30 01:44:19 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak" 2025/04/30 01:44:20 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestNothingToTransferWithoutEmptyDirs (45.04s) PASS 2025/04/30 01:44:22 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-sabikek0yata': Purge remote "./sync.test -test.v -test.timeout 1h0m0s -remote TestCryptDrive: -verbose -fast-list" - Finished OK in 16m10.475545758s (try 1/5)