"./sync.test -test.v -test.timeout 1h0m0s -remote TestCryptDrive: -verbose" - Starting (try 1/5) 2025/03/14 06:16:11 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-bebopij4liga" 2025/03/14 06:16:11 DEBUG : Using config file from "/home/rclone/.rclone.conf" 2025/03/14 06:16:11 DEBUG : Creating backend with remote "TestDrive:crypt/qkf5a5egif24gge3mq1m89pdh9bhtg3f78co71af63vrvok79gm0" 2025/03/14 06:16:12 DEBUG : Creating backend with remote "/tmp/rclone492104059" === RUN TestPipe --- PASS: TestPipe (0.00s) === RUN TestPipeConcurrent --- PASS: TestPipeConcurrent (0.04s) === RUN TestPipeOrderBy === RUN TestPipeOrderBy/#00 === RUN TestPipeOrderBy/size === RUN TestPipeOrderBy/name === RUN TestPipeOrderBy/modtime === RUN TestPipeOrderBy/size,ascending === RUN TestPipeOrderBy/name,asc === RUN TestPipeOrderBy/modtime,ascending === RUN TestPipeOrderBy/size,descending === RUN TestPipeOrderBy/name,desc === RUN TestPipeOrderBy/modtime,descending === RUN TestPipeOrderBy/size,mixed,50 === RUN TestPipeOrderBy/size,mixed,51 --- PASS: TestPipeOrderBy (0.00s) --- PASS: TestPipeOrderBy/#00 (0.00s) --- PASS: TestPipeOrderBy/size (0.00s) --- PASS: TestPipeOrderBy/name (0.00s) --- PASS: TestPipeOrderBy/modtime (0.00s) --- PASS: TestPipeOrderBy/size,ascending (0.00s) --- PASS: TestPipeOrderBy/name,asc (0.00s) --- PASS: TestPipeOrderBy/modtime,ascending (0.00s) --- PASS: TestPipeOrderBy/size,descending (0.00s) --- PASS: TestPipeOrderBy/name,desc (0.00s) --- PASS: TestPipeOrderBy/modtime,descending (0.00s) --- PASS: TestPipeOrderBy/size,mixed,50 (0.00s) --- PASS: TestPipeOrderBy/size,mixed,51 (0.00s) === RUN TestNewLess === RUN TestNewLess/blankOK === RUN TestNewLess/tooManyParts === RUN TestNewLess/tooManyParts2 === RUN TestNewLess/badMixed === RUN TestNewLess/unknownComparison === RUN TestNewLess/unknownSortDirection === RUN TestNewLess/size === RUN TestNewLess/name === RUN TestNewLess/modtime === RUN TestNewLess/size,ascending === RUN TestNewLess/name,asc === RUN TestNewLess/modtime,ascending === RUN TestNewLess/size,descending === RUN TestNewLess/name,desc === RUN TestNewLess/modtime,descending === RUN TestNewLess/modtime,mixed === RUN TestNewLess/modtime,mixed,30 --- PASS: TestNewLess (0.00s) --- PASS: TestNewLess/blankOK (0.00s) --- PASS: TestNewLess/tooManyParts (0.00s) --- PASS: TestNewLess/tooManyParts2 (0.00s) --- PASS: TestNewLess/badMixed (0.00s) --- PASS: TestNewLess/unknownComparison (0.00s) --- PASS: TestNewLess/unknownSortDirection (0.00s) --- PASS: TestNewLess/size (0.00s) --- PASS: TestNewLess/name (0.00s) --- PASS: TestNewLess/modtime (0.00s) --- PASS: TestNewLess/size,ascending (0.00s) --- PASS: TestNewLess/name,asc (0.00s) --- PASS: TestNewLess/modtime,ascending (0.00s) --- PASS: TestNewLess/size,descending (0.00s) --- PASS: TestNewLess/name,desc (0.00s) --- PASS: TestNewLess/modtime,descending (0.00s) --- PASS: TestNewLess/modtime,mixed (0.00s) --- PASS: TestNewLess/modtime,mixed,30 (0.00s) === RUN TestRcCopy rc_test.go:16: Skipping test on non local remote --- SKIP: TestRcCopy (0.00s) === RUN TestRcMove rc_test.go:16: Skipping test on non local remote --- SKIP: TestRcMove (0.00s) === RUN TestRcSync rc_test.go:16: Skipping test on non local remote --- SKIP: TestRcSync (0.00s) === RUN TestCopyWithDryRun run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-bebopij4liga'", Local "Local file system at /tmp/rclone492104059", Modify Window "1ms" 2025/03/14 06:16:13 DEBUG : Added delayed dir = "sub dir", newDst= 2025/03/14 06:16:13 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2025/03/14 06:16:13 NOTICE: sub dir/hello world: Skipped copy as --dry-run is set (size 11) 2025/03/14 06:16:13 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-bebopij4liga': Waiting for checks to finish 2025/03/14 06:16:13 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-bebopij4liga': Waiting for transfers to finish 2025/03/14 06:16:13 NOTICE: sub dir: Skipped set directory modification time as --dry-run is set run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-bebopij4liga'", Local "Local file system at /tmp/rclone492104059", Modify Window "1ms" --- PASS: TestCopyWithDryRun (2.44s) === RUN TestCopy run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-bebopij4liga'", Local "Local file system at /tmp/rclone492104059", Modify Window "1ms" 2025/03/14 06:16:15 INFO : sub dir: Set directory modification time (using DirSetModTime) 2025/03/14 06:16:15 DEBUG : Added delayed dir = "sub dir", newDst= 2025/03/14 06:16:15 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2025/03/14 06:16:15 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-bebopij4liga': Waiting for checks to finish 2025/03/14 06:16:15 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-bebopij4liga': Waiting for transfers to finish 2025/03/14 06:16:17 DEBUG : sub dir/hello world: md5 = dfe36325743259716cfb3be5083b4a57 OK 2025/03/14 06:16:17 INFO : sub dir/hello world: Copied (new) 2025/03/14 06:16:18 INFO : sub dir: Set directory modification time (using DirSetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-bebopij4liga'", Local "Local file system at /tmp/rclone492104059", Modify Window "1ms" 2025/03/14 06:16:20 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestCopy (6.68s) === RUN TestCopyMetadata run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-bebopij4liga'", Local "Local file system at /tmp/rclone492104059", Modify Window "1ms" 2025/03/14 06:16:21 DEBUG : metadata sub dir: Making directory with metadata 2025/03/14 06:16:21 INFO : metadata sub dir: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2025/03/14 06:16:21 DEBUG : empty metadata sub dir: Making directory with metadata 2025/03/14 06:16:21 INFO : empty metadata sub dir: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2025/03/14 06:16:21 DEBUG : Local file system at /tmp/rclone492104059: File to upload is small (21 bytes), uploading instead of streaming 2025/03/14 06:16:21 DEBUG : metadata sub dir/hello metadata world: md5 = baa7a013449dbba2b1ed02b5cfb4e1a2 OK 2025/03/14 06:16:21 DEBUG : metadata sub dir/hello metadata world: Size and md5 of src and dst objects identical 2025/03/14 06:16:21 INFO : metadata sub dir: Set directory modification time (using DirSetModTime) 2025/03/14 06:16:22 DEBUG : Google drive root 'crypt/qkf5a5egif24gge3mq1m89pdh9bhtg3f78co71af63vrvok79gm0': Skipping btime metadata as can't update it on an existing file: 2025-03-14T06:16:21.85001847Z 2025/03/14 06:16:22 INFO : empty metadata sub dir: Updated directory metadata 2025/03/14 06:16:23 DEBUG : Google drive root 'crypt/qkf5a5egif24gge3mq1m89pdh9bhtg3f78co71af63vrvok79gm0': Skipping btime metadata as can't update it on an existing file: 2025-03-14T06:16:21.85001847Z 2025/03/14 06:16:23 INFO : metadata sub dir: Updated directory metadata 2025/03/14 06:16:23 DEBUG : metadata sub dir/hello metadata world: Need to transfer - File not found at Destination 2025/03/14 06:16:23 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-bebopij4liga': Waiting for checks to finish 2025/03/14 06:16:23 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-bebopij4liga': Waiting for transfers to finish 2025/03/14 06:16:25 DEBUG : metadata sub dir/hello metadata world: md5 = f2a94ccf2a147f402e4a74a253675f03 OK 2025/03/14 06:16:25 INFO : metadata sub dir/hello metadata world: Copied (new) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-bebopij4liga'", Local "Local file system at /tmp/rclone492104059", Modify Window "1ms" 2025/03/14 06:16:28 DEBUG : fg45q1rm3kh00nmmkk4m6ihmrcnel1p7551kqhjr9bk2gtd2gbf0: Rmdir: contains trashed file: "dmuvulfij81f693ur0f1vvbvq9v6iscp56daas3m51n9li5e3470" --- PASS: TestCopyMetadata (8.63s) === RUN TestCopyMetadataNoEmptyDirs run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-bebopij4liga'", Local "Local file system at /tmp/rclone492104059", Modify Window "1ms" 2025/03/14 06:16:30 DEBUG : metadata sub dir: Making directory with metadata 2025/03/14 06:16:30 INFO : metadata sub dir: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2025/03/14 06:16:30 DEBUG : empty metadata sub dir: Making directory with metadata 2025/03/14 06:16:30 INFO : empty metadata sub dir: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2025/03/14 06:16:30 DEBUG : Local file system at /tmp/rclone492104059: File to upload is small (21 bytes), uploading instead of streaming 2025/03/14 06:16:30 DEBUG : metadata sub dir/hello metadata world: md5 = baa7a013449dbba2b1ed02b5cfb4e1a2 OK 2025/03/14 06:16:30 DEBUG : metadata sub dir/hello metadata world: Size and md5 of src and dst objects identical 2025/03/14 06:16:30 INFO : metadata sub dir: Set directory modification time (using DirSetModTime) 2025/03/14 06:16:30 DEBUG : Added delayed dir = "empty metadata sub dir", newDst= 2025/03/14 06:16:30 DEBUG : Added delayed dir = "metadata sub dir", newDst= 2025/03/14 06:16:30 DEBUG : metadata sub dir/hello metadata world: Need to transfer - File not found at Destination 2025/03/14 06:16:30 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-bebopij4liga': Waiting for checks to finish 2025/03/14 06:16:30 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-bebopij4liga': Waiting for transfers to finish 2025/03/14 06:16:32 DEBUG : metadata sub dir/hello metadata world: md5 = 11292f815f66ebe48889dd81d19c354a OK 2025/03/14 06:16:32 INFO : metadata sub dir/hello metadata world: Copied (new) 2025/03/14 06:16:32 DEBUG : Google drive root 'crypt/qkf5a5egif24gge3mq1m89pdh9bhtg3f78co71af63vrvok79gm0': Skipping btime metadata as can't update it on an existing file: 2025-03-14T06:16:30.473960736Z 2025/03/14 06:16:33 INFO : metadata sub dir: Updated directory metadata run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-bebopij4liga'", Local "Local file system at /tmp/rclone492104059", Modify Window "1ms" 2025/03/14 06:16:36 DEBUG : fg45q1rm3kh00nmmkk4m6ihmrcnel1p7551kqhjr9bk2gtd2gbf0: Rmdir: contains trashed file: "dmuvulfij81f693ur0f1vvbvq9v6iscp56daas3m51n9li5e3470" --- PASS: TestCopyMetadataNoEmptyDirs (7.18s) === RUN TestCopyMissingDirectory run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-bebopij4liga'", Local "Local file system at /tmp/rclone492104059", Modify Window "1ms" 2025/03/14 06:16:37 DEBUG : Creating backend with remote "/non-existing" 2025/03/14 06:16:37 ERROR : Local file system at /non-existing: error reading source root directory: directory not found 2025/03/14 06:16:37 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-bebopij4liga': Waiting for checks to finish 2025/03/14 06:16:37 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-bebopij4liga': Waiting for transfers to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-bebopij4liga'", Local "Local file system at /tmp/rclone492104059", Modify Window "1ms" --- PASS: TestCopyMissingDirectory (1.23s) === RUN TestCopyNoTraverse run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-bebopij4liga'", Local "Local file system at /tmp/rclone492104059", Modify Window "1ms" 2025/03/14 06:16:38 DEBUG : Added delayed dir = "sub dir", newDst= 2025/03/14 06:16:39 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2025/03/14 06:16:39 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-bebopij4liga': Waiting for checks to finish 2025/03/14 06:16:39 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-bebopij4liga': Waiting for transfers to finish 2025/03/14 06:16:41 DEBUG : sub dir/hello world: md5 = 0c190d2c1ea34c41de6375bde8adb34a OK 2025/03/14 06:16:41 INFO : sub dir/hello world: Copied (new) 2025/03/14 06:16:42 INFO : sub dir: Set directory modification time (using DirSetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-bebopij4liga'", Local "Local file system at /tmp/rclone492104059", Modify Window "1ms" 2025/03/14 06:16:43 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestCopyNoTraverse (6.52s) === RUN TestCopyCheckFirst run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-bebopij4liga'", Local "Local file system at /tmp/rclone492104059", Modify Window "1ms" 2025/03/14 06:16:45 INFO : Encrypted drive 'TestCryptDrive:rclone-test-bebopij4liga': Running all checks before starting transfers 2025/03/14 06:16:45 DEBUG : Added delayed dir = "sub dir", newDst= 2025/03/14 06:16:45 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2025/03/14 06:16:45 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-bebopij4liga': Waiting for checks to finish 2025/03/14 06:16:45 INFO : Encrypted drive 'TestCryptDrive:rclone-test-bebopij4liga': Checks finished, now starting transfers 2025/03/14 06:16:45 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-bebopij4liga': Waiting for transfers to finish 2025/03/14 06:16:47 DEBUG : sub dir/hello world: md5 = 1423dc474f0a511c3883c8a4239efacb OK 2025/03/14 06:16:47 INFO : sub dir/hello world: Copied (new) 2025/03/14 06:16:48 INFO : sub dir: Set directory modification time (using DirSetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-bebopij4liga'", Local "Local file system at /tmp/rclone492104059", Modify Window "1ms" 2025/03/14 06:16:50 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestCopyCheckFirst (6.07s) === RUN TestSyncNoTraverse run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-bebopij4liga'", Local "Local file system at /tmp/rclone492104059", Modify Window "1ms" 2025/03/14 06:16:51 ERROR : Ignoring --no-traverse with sync 2025/03/14 06:16:51 DEBUG : Added delayed dir = "sub dir", newDst= 2025/03/14 06:16:51 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2025/03/14 06:16:51 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-bebopij4liga': Waiting for checks to finish 2025/03/14 06:16:51 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-bebopij4liga': Waiting for transfers to finish 2025/03/14 06:16:53 DEBUG : sub dir/hello world: md5 = 0ddd16e130589ca3d586404e08af8c26 OK 2025/03/14 06:16:53 INFO : sub dir/hello world: Copied (new) 2025/03/14 06:16:53 DEBUG : Waiting for deletions to finish 2025/03/14 06:16:54 INFO : sub dir: Set directory modification time (using DirSetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-bebopij4liga'", Local "Local file system at /tmp/rclone492104059", Modify Window "1ms" 2025/03/14 06:16:56 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestSyncNoTraverse (7.82s) === RUN TestCopyWithDepth run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-bebopij4liga'", Local "Local file system at /tmp/rclone492104059", Modify Window "1ms" 2025/03/14 06:16:59 DEBUG : hello world2: Need to transfer - File not found at Destination 2025/03/14 06:16:59 DEBUG : Added delayed dir = "sub dir", newDst= 2025/03/14 06:16:59 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-bebopij4liga': Waiting for checks to finish 2025/03/14 06:16:59 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-bebopij4liga': Waiting for transfers to finish 2025/03/14 06:17:01 DEBUG : hello world2: md5 = 00e9726aa150c8d37ab439a506d7e561 OK 2025/03/14 06:17:01 INFO : hello world2: Copied (new) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-bebopij4liga'", Local "Local file system at /tmp/rclone492104059", Modify Window "1ms" --- PASS: TestCopyWithDepth (3.52s) === RUN TestCopyWithFilesFrom run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-bebopij4liga'", Local "Local file system at /tmp/rclone492104059", Modify Window "1ms" 2025/03/14 06:17:03 DEBUG : potato2: Need to transfer - File not found at Destination 2025/03/14 06:17:03 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-bebopij4liga': Waiting for checks to finish 2025/03/14 06:17:03 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-bebopij4liga': Waiting for transfers to finish 2025/03/14 06:17:04 DEBUG : potato2: md5 = 4d8115e639f430b7008ccb6089fe3a1a OK 2025/03/14 06:17:04 INFO : potato2: Copied (new) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-bebopij4liga'", Local "Local file system at /tmp/rclone492104059", Modify Window "1ms" --- PASS: TestCopyWithFilesFrom (3.38s) === RUN TestCopyWithFilesFromAndNoTraverse run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-bebopij4liga'", Local "Local file system at /tmp/rclone492104059", Modify Window "1ms" 2025/03/14 06:17:06 DEBUG : potato2: Need to transfer - File not found at Destination 2025/03/14 06:17:06 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-bebopij4liga': Waiting for checks to finish 2025/03/14 06:17:06 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-bebopij4liga': Waiting for transfers to finish 2025/03/14 06:17:07 DEBUG : potato2: md5 = 1c5cbe51e82c698bba82c1bd25de264f OK 2025/03/14 06:17:07 INFO : potato2: Copied (new) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-bebopij4liga'", Local "Local file system at /tmp/rclone492104059", Modify Window "1ms" --- PASS: TestCopyWithFilesFromAndNoTraverse (3.33s) === RUN TestCopyEmptyDirectories run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-bebopij4liga'", Local "Local file system at /tmp/rclone492104059", Modify Window "1ms" 2025/03/14 06:17:09 DEBUG : sub dir2/sub sub dir2: Making directory with metadata 2025/03/14 06:17:09 INFO : sub dir2/sub sub dir2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2025/03/14 06:17:09 INFO : sub dir2: Set directory modification time (using DirSetModTime) 2025/03/14 06:17:09 INFO : sub dir: Set directory modification time (using DirSetModTime) 2025/03/14 06:17:09 DEBUG : sub dir: Making directory with metadata 2025/03/14 06:17:10 INFO : sub dir: Made directory with metadata (mtime=2001-02-03T04:05:06.499999999Z) 2025/03/14 06:17:10 DEBUG : sub dir2: Making directory with metadata 2025/03/14 06:17:11 INFO : sub dir2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2025/03/14 06:17:11 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2025/03/14 06:17:11 DEBUG : sub dir2/sub sub dir2: Making directory with metadata 2025/03/14 06:17:12 INFO : sub dir2/sub sub dir2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2025/03/14 06:17:12 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-bebopij4liga': Waiting for checks to finish 2025/03/14 06:17:12 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-bebopij4liga': Waiting for transfers to finish 2025/03/14 06:17:13 DEBUG : sub dir/hello world: md5 = 53a77f55a1970472f0f6b0c6fe6dea50 OK 2025/03/14 06:17:13 INFO : sub dir/hello world: Copied (new) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-bebopij4liga'", Local "Local file system at /tmp/rclone492104059", Modify Window "1ms" 2025/03/14 06:17:16 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc: Rmdir: contains trashed file: "cv6a9uf28ngrajena8kt5ijjn0" 2025/03/14 06:17:17 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestCopyEmptyDirectories (9.35s) === RUN TestCopyNoEmptyDirectories run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-bebopij4liga'", Local "Local file system at /tmp/rclone492104059", Modify Window "1ms" 2025/03/14 06:17:18 INFO : sub dir2: Making directory 2025/03/14 06:17:18 DEBUG : sub dir2/sub sub dir2: Making directory with metadata 2025/03/14 06:17:18 INFO : sub dir2/sub sub dir2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2025/03/14 06:17:19 DEBUG : Added delayed dir = "sub dir", newDst= 2025/03/14 06:17:19 DEBUG : Added delayed dir = "sub dir2", newDst= 2025/03/14 06:17:19 DEBUG : Added delayed dir = "sub dir2/sub sub dir2", newDst= 2025/03/14 06:17:19 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2025/03/14 06:17:19 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-bebopij4liga': Waiting for checks to finish 2025/03/14 06:17:19 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-bebopij4liga': Waiting for transfers to finish 2025/03/14 06:17:21 DEBUG : sub dir/hello world: md5 = 7bc82a222b29154fbd332ebe9596b23b OK 2025/03/14 06:17:21 INFO : sub dir/hello world: Copied (new) 2025/03/14 06:17:22 INFO : sub dir: Set directory modification time (using DirSetModTime) 2025/03/14 06:17:23 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestCopyNoEmptyDirectories (5.64s) === RUN TestMoveEmptyDirectories run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-bebopij4liga'", Local "Local file system at /tmp/rclone492104059", Modify Window "1ms" 2025/03/14 06:17:24 DEBUG : sub dir2: Making directory with metadata 2025/03/14 06:17:24 INFO : sub dir2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2025/03/14 06:17:24 DEBUG : sub dir: Making directory with metadata 2025/03/14 06:17:25 INFO : sub dir: Made directory with metadata (mtime=2025-03-14T06:17:24.509598731Z) 2025/03/14 06:17:25 DEBUG : sub dir2: Making directory with metadata 2025/03/14 06:17:26 INFO : sub dir2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2025/03/14 06:17:26 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2025/03/14 06:17:26 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-bebopij4liga': Waiting for checks to finish 2025/03/14 06:17:26 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-bebopij4liga': Waiting for transfers to finish 2025/03/14 06:17:27 DEBUG : sub dir/hello world: md5 = cd427e1b27cc4a71112be9d182e683b4 OK 2025/03/14 06:17:27 INFO : sub dir/hello world: Copied (new) 2025/03/14 06:17:27 INFO : sub dir/hello world: Deleted run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-bebopij4liga'", Local "Local file system at /tmp/rclone492104059", Modify Window "1ms" 2025/03/14 06:17:31 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestMoveEmptyDirectories (7.70s) === RUN TestSyncNoUpdateDirModtime run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-bebopij4liga'", Local "Local file system at /tmp/rclone492104059", Modify Window "1ms" 2025/03/14 06:17:32 DEBUG : sub dir no update dir modtime: Making directory with metadata 2025/03/14 06:17:32 INFO : sub dir no update dir modtime: Made directory with metadata (mtime=2001-02-03T04:05:06.499999999Z) 2025/03/14 06:17:33 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-bebopij4liga': Waiting for checks to finish 2025/03/14 06:17:33 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-bebopij4liga': Waiting for transfers to finish 2025/03/14 06:17:33 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-bebopij4liga'", Local "Local file system at /tmp/rclone492104059", Modify Window "1ms" --- PASS: TestSyncNoUpdateDirModtime (4.31s) === RUN TestMoveNoEmptyDirectories run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-bebopij4liga'", Local "Local file system at /tmp/rclone492104059", Modify Window "1ms" 2025/03/14 06:17:36 INFO : sub dir2: Making directory 2025/03/14 06:17:36 DEBUG : Added delayed dir = "sub dir", newDst= 2025/03/14 06:17:36 DEBUG : Added delayed dir = "sub dir2", newDst= 2025/03/14 06:17:36 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2025/03/14 06:17:36 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-bebopij4liga': Waiting for checks to finish 2025/03/14 06:17:36 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-bebopij4liga': Waiting for transfers to finish 2025/03/14 06:17:38 DEBUG : sub dir/hello world: md5 = 122ed869fa0693c25a31715fc8a6ebdf OK 2025/03/14 06:17:38 INFO : sub dir/hello world: Copied (new) 2025/03/14 06:17:38 INFO : sub dir/hello world: Deleted 2025/03/14 06:17:39 INFO : sub dir: Set directory modification time (using DirSetModTime) 2025/03/14 06:17:41 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestMoveNoEmptyDirectories (5.28s) === RUN TestSyncEmptyDirectories run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-bebopij4liga'", Local "Local file system at /tmp/rclone492104059", Modify Window "1ms" 2025/03/14 06:17:41 DEBUG : sub dir2: Making directory with metadata 2025/03/14 06:17:41 INFO : sub dir2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2025/03/14 06:17:41 INFO : sub dir: Set directory modification time (using DirSetModTime) 2025/03/14 06:17:42 DEBUG : sub dir: Making directory with metadata 2025/03/14 06:17:42 INFO : sub dir: Made directory with metadata (mtime=2001-02-03T04:05:06.499999999Z) 2025/03/14 06:17:42 DEBUG : sub dir2: Making directory with metadata 2025/03/14 06:17:43 INFO : sub dir2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2025/03/14 06:17:43 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2025/03/14 06:17:43 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-bebopij4liga': Waiting for checks to finish 2025/03/14 06:17:43 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-bebopij4liga': Waiting for transfers to finish 2025/03/14 06:17:45 DEBUG : sub dir/hello world: md5 = 148a8135158997c9dd5d78e62f0affae OK 2025/03/14 06:17:45 INFO : sub dir/hello world: Copied (new) 2025/03/14 06:17:45 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-bebopij4liga'", Local "Local file system at /tmp/rclone492104059", Modify Window "1ms" 2025/03/14 06:17:48 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestSyncEmptyDirectories (7.42s) === RUN TestSyncSetDelayedModTimes run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-bebopij4liga'", Local "Local file system at /tmp/rclone492104059", Modify Window "1ms" sync_test.go:507: Backend doesn't have DirModTimeUpdatesOnWrite set --- SKIP: TestSyncSetDelayedModTimes (0.50s) === RUN TestSyncNoEmptyDirectories run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-bebopij4liga'", Local "Local file system at /tmp/rclone492104059", Modify Window "1ms" 2025/03/14 06:17:49 INFO : sub dir2: Making directory 2025/03/14 06:17:49 DEBUG : Added delayed dir = "sub dir", newDst= 2025/03/14 06:17:49 DEBUG : Added delayed dir = "sub dir2", newDst= 2025/03/14 06:17:49 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2025/03/14 06:17:49 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-bebopij4liga': Waiting for checks to finish 2025/03/14 06:17:49 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-bebopij4liga': Waiting for transfers to finish 2025/03/14 06:17:52 DEBUG : sub dir/hello world: md5 = 6a653ac65f4eb85fc08a880766a39bf4 OK 2025/03/14 06:17:52 INFO : sub dir/hello world: Copied (new) 2025/03/14 06:17:52 DEBUG : Waiting for deletions to finish 2025/03/14 06:17:52 INFO : sub dir: Set directory modification time (using DirSetModTime) 2025/03/14 06:17:54 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestSyncNoEmptyDirectories (5.56s) === RUN TestServerSideCopy run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-bebopij4liga'", Local "Local file system at /tmp/rclone492104059", Modify Window "1ms" 2025/03/14 06:17:57 DEBUG : sub dir/hello world: md5 = deb3c767e63b93eda58824f3be39ce78 OK 2025/03/14 06:17:58 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-zikakec4pafe" 2025/03/14 06:17:58 DEBUG : Creating backend with remote "TestDrive:crypt/ti80mqha93kiu3dont4lj8i4nv4fptkcj9mm20vf00dg1ph17kpg" sync_test.go:590: Server side copy (if possible) Encrypted drive 'TestCryptDrive:rclone-test-bebopij4liga' -> Encrypted drive 'TestCryptDrive:rclone-test-zikakec4pafe' 2025/03/14 06:17:59 DEBUG : Added delayed dir = "sub dir", newDst= 2025/03/14 06:17:59 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2025/03/14 06:17:59 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zikakec4pafe': Waiting for checks to finish 2025/03/14 06:17:59 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zikakec4pafe': Waiting for transfers to finish 2025/03/14 06:18:02 INFO : sub dir/hello world: Copied (server-side copy) 2025/03/14 06:18:02 INFO : sub dir: Set directory modification time (using DirSetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-bebopij4liga'", Local "Local file system at /tmp/rclone492104059", Modify Window "1ms" 2025/03/14 06:18:03 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zikakec4pafe': Purge remote 2025/03/14 06:18:04 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestServerSideCopy (10.71s) === RUN TestCopyOverSelf run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-bebopij4liga'", Local "Local file system at /tmp/rclone492104059", Modify Window "1ms" 2025/03/14 06:18:08 DEBUG : sub dir/hello world: md5 = d770650c0b27401289314c82934db891 OK 2025/03/14 06:18:09 INFO : sub dir: Set directory modification time (using SetModTime) 2025/03/14 06:18:09 DEBUG : Added delayed dir = "sub dir", newDst=sub dir 2025/03/14 06:18:09 DEBUG : sub dir/hello world: Sizes differ (src 17 vs dst 11) 2025/03/14 06:18:09 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-bebopij4liga': Waiting for checks to finish 2025/03/14 06:18:09 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-bebopij4liga': Waiting for transfers to finish 2025/03/14 06:18:11 DEBUG : sub dir/hello world: md5 = ca9a71a2519d1b9591b5f1d10be76f85 OK 2025/03/14 06:18:11 INFO : sub dir/hello world: Copied (replaced existing) 2025/03/14 06:18:11 INFO : sub dir: Set directory modification time (using SetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-bebopij4liga'", Local "Local file system at /tmp/rclone492104059", Modify Window "1ms" 2025/03/14 06:18:13 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestCopyOverSelf (8.52s) === RUN TestServerSideCopyOverSelf run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-bebopij4liga'", Local "Local file system at /tmp/rclone492104059", Modify Window "1ms" 2025/03/14 06:18:16 DEBUG : sub dir/hello world: md5 = 8dfda4a72ed1f7fd756f8d5359e6fb3a OK 2025/03/14 06:18:17 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-jalabad3rasi" 2025/03/14 06:18:17 DEBUG : Creating backend with remote "TestDrive:crypt/5qh38vhijo3u12424uhee4m14cma0fg3sbnf9uu3uhrd93a589ag" sync_test.go:626: Server side copy (if possible) Encrypted drive 'TestCryptDrive:rclone-test-bebopij4liga' -> Encrypted drive 'TestCryptDrive:rclone-test-jalabad3rasi' 2025/03/14 06:18:18 DEBUG : Added delayed dir = "sub dir", newDst= 2025/03/14 06:18:18 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2025/03/14 06:18:18 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-jalabad3rasi': Waiting for checks to finish 2025/03/14 06:18:18 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-jalabad3rasi': Waiting for transfers to finish 2025/03/14 06:18:21 INFO : sub dir/hello world: Copied (server-side copy) 2025/03/14 06:18:21 INFO : sub dir: Set directory modification time (using DirSetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-bebopij4liga'", Local "Local file system at /tmp/rclone492104059", Modify Window "1ms" 2025/03/14 06:18:23 DEBUG : sub dir/hello world: md5 = 1f3d06c67031812864859693ba31120c OK 2025/03/14 06:18:24 DEBUG : sub dir: Directory modification time the same (differ by 0s, within tolerance 1ms) 2025/03/14 06:18:24 DEBUG : Added delayed dir = "sub dir", newDst=sub dir 2025/03/14 06:18:24 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-jalabad3rasi': Waiting for checks to finish 2025/03/14 06:18:24 DEBUG : sub dir/hello world: Sizes differ (src 17 vs dst 11) 2025/03/14 06:18:24 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-jalabad3rasi': Waiting for transfers to finish 2025/03/14 06:18:26 INFO : sub dir/hello world: Copied (server-side copy) 2025/03/14 06:18:26 INFO : sub dir: Set directory modification time (using SetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-bebopij4liga'", Local "Local file system at /tmp/rclone492104059", Modify Window "1ms" 2025/03/14 06:18:27 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-jalabad3rasi': Purge remote 2025/03/14 06:18:29 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestServerSideCopyOverSelf (16.28s) === RUN TestMoveOverSelf run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-bebopij4liga'", Local "Local file system at /tmp/rclone492104059", Modify Window "1ms" 2025/03/14 06:18:33 DEBUG : sub dir/hello world: md5 = fdbaf5f090ccbd8e409cd20bbaaf2af6 OK 2025/03/14 06:18:34 INFO : sub dir: Set directory modification time (using SetModTime) 2025/03/14 06:18:34 DEBUG : Added delayed dir = "sub dir", newDst=sub dir 2025/03/14 06:18:34 DEBUG : sub dir/hello world: Sizes differ (src 17 vs dst 11) 2025/03/14 06:18:34 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-bebopij4liga': Waiting for checks to finish 2025/03/14 06:18:34 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-bebopij4liga': Waiting for transfers to finish 2025/03/14 06:18:35 DEBUG : sub dir/hello world: md5 = 7ddc705c4e0a1b895e3f85de7764a439 OK 2025/03/14 06:18:35 INFO : sub dir/hello world: Copied (replaced existing) 2025/03/14 06:18:35 INFO : sub dir/hello world: Deleted 2025/03/14 06:18:36 INFO : sub dir: Set directory modification time (using SetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-bebopij4liga'", Local "Local file system at /tmp/rclone492104059", Modify Window "1ms" 2025/03/14 06:18:37 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestMoveOverSelf (8.23s) === RUN TestServerSideMoveOverSelf run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-bebopij4liga'", Local "Local file system at /tmp/rclone492104059", Modify Window "1ms" 2025/03/14 06:18:41 DEBUG : sub dir/hello world: md5 = 31ea3ba0ce4f347c002a6f7af2457cbe OK 2025/03/14 06:18:41 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-tagucic3zisi" 2025/03/14 06:18:41 DEBUG : Creating backend with remote "TestDrive:crypt/mer9ngheoe4bbkaaj4g5i47c9bgk46721du0spcegpksq5ogc5q0" sync_test.go:671: Server side copy (if possible) Encrypted drive 'TestCryptDrive:rclone-test-bebopij4liga' -> Encrypted drive 'TestCryptDrive:rclone-test-tagucic3zisi' 2025/03/14 06:18:43 DEBUG : Added delayed dir = "sub dir", newDst= 2025/03/14 06:18:43 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2025/03/14 06:18:43 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tagucic3zisi': Waiting for checks to finish 2025/03/14 06:18:43 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tagucic3zisi': Waiting for transfers to finish 2025/03/14 06:18:45 INFO : sub dir/hello world: Copied (server-side copy) 2025/03/14 06:18:46 INFO : sub dir: Set directory modification time (using DirSetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-bebopij4liga'", Local "Local file system at /tmp/rclone492104059", Modify Window "1ms" 2025/03/14 06:18:48 DEBUG : sub dir/hello world: md5 = 83a5a78c0dc886407b1724b345ad853e OK 2025/03/14 06:18:49 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tagucic3zisi': Using server-side directory move 2025/03/14 06:18:49 INFO : Encrypted drive 'TestCryptDrive:rclone-test-tagucic3zisi': Server side directory move failed - fallback to file moves: can't copy directory - destination already exists 2025/03/14 06:18:49 DEBUG : sub dir: Directory modification time the same (differ by 0s, within tolerance 1ms) 2025/03/14 06:18:49 DEBUG : Added delayed dir = "sub dir", newDst=sub dir 2025/03/14 06:18:49 DEBUG : sub dir/hello world: Sizes differ (src 17 vs dst 11) 2025/03/14 06:18:49 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tagucic3zisi': Waiting for checks to finish 2025/03/14 06:18:49 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tagucic3zisi': Waiting for transfers to finish 2025/03/14 06:18:50 INFO : sub dir/hello world: Deleted 2025/03/14 06:18:50 INFO : sub dir/hello world: Moved (server-side) 2025/03/14 06:18:51 INFO : sub dir: Set directory modification time (using SetModTime) 2025/03/14 06:18:53 DEBUG : sub dir/hello world: md5 = 14a06ddf509ce75a6a9bb3b5ab3f7809 OK 2025/03/14 06:18:54 DEBUG : testing file moves 2025/03/14 06:18:54 DEBUG : sub dir: Directory modification time the same (differ by 0s, within tolerance 1ms) 2025/03/14 06:18:54 DEBUG : Added delayed dir = "sub dir", newDst=sub dir 2025/03/14 06:18:54 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tagucic3zisi': Waiting for checks to finish 2025/03/14 06:18:54 DEBUG : sub dir/hello world: Sizes differ (src 24 vs dst 17) 2025/03/14 06:18:54 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tagucic3zisi': Waiting for transfers to finish 2025/03/14 06:18:55 INFO : sub dir/hello world: Deleted 2025/03/14 06:18:55 INFO : sub dir/hello world: Moved (server-side) 2025/03/14 06:18:56 INFO : sub dir: Set directory modification time (using SetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-bebopij4liga'", Local "Local file system at /tmp/rclone492104059", Modify Window "1ms" 2025/03/14 06:18:57 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tagucic3zisi': Purge remote --- PASS: TestServerSideMoveOverSelf (21.01s) === RUN TestCopyAfterDelete run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-bebopij4liga'", Local "Local file system at /tmp/rclone492104059", Modify Window "1ms" 2025/03/14 06:19:02 DEBUG : sub dir/hello world: md5 = ec878bec648060fab0f8bf26165231c5 OK 2025/03/14 06:19:02 ERROR : : error listing: directory not found 2025/03/14 06:19:02 INFO : Local file system at /tmp/rclone492104059: Making directory 2025/03/14 06:19:03 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-bebopij4liga': Waiting for checks to finish 2025/03/14 06:19:03 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-bebopij4liga': Waiting for transfers to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-bebopij4liga'", Local "Local file system at /tmp/rclone492104059", Modify Window "1ms" 2025/03/14 06:19:04 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestCopyAfterDelete (6.04s) === RUN TestCopyRedownload run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-bebopij4liga'", Local "Local file system at /tmp/rclone492104059", Modify Window "1ms" 2025/03/14 06:19:08 DEBUG : sub dir/hello world: md5 = 28b1fe9989c788072e2ed55e7a0b4512 OK 2025/03/14 06:19:08 DEBUG : Added delayed dir = "sub dir", newDst= 2025/03/14 06:19:09 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2025/03/14 06:19:09 DEBUG : Local file system at /tmp/rclone492104059: Waiting for checks to finish 2025/03/14 06:19:09 DEBUG : Local file system at /tmp/rclone492104059: Waiting for transfers to finish 2025/03/14 06:19:10 DEBUG : sub dir/hello world.285f0a30.partial: renamed to: sub dir/hello world 2025/03/14 06:19:10 INFO : sub dir/hello world: Copied (new) 2025/03/14 06:19:10 INFO : sub dir: Set directory modification time (using DirSetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-bebopij4liga'", Local "Local file system at /tmp/rclone492104059", Modify Window "1ms" 2025/03/14 06:19:11 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestCopyRedownload (6.55s) === RUN TestSyncBasedOnCheckSum run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-bebopij4liga'", Local "Local file system at /tmp/rclone492104059", Modify Window "1ms" 2025/03/14 06:19:12 DEBUG : check sum: Need to transfer - File not found at Destination 2025/03/14 06:19:12 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-bebopij4liga': Waiting for checks to finish 2025/03/14 06:19:12 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-bebopij4liga': Waiting for transfers to finish 2025/03/14 06:19:14 DEBUG : check sum: md5 = 4db68d8345ae063ca4b4dcebb3269a5a OK 2025/03/14 06:19:14 INFO : check sum: Copied (new) 2025/03/14 06:19:14 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-bebopij4liga'", Local "Local file system at /tmp/rclone492104059", Modify Window "1ms" 2025/03/14 06:19:14 NOTICE: Encrypted drive 'TestCryptDrive:rclone-test-bebopij4liga': --checksum is in use but the source and destination have no hashes in common; falling back to --size-only 2025/03/14 06:19:14 DEBUG : check sum: Size of src and dst objects identical 2025/03/14 06:19:14 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-bebopij4liga': Waiting for checks to finish 2025/03/14 06:19:14 DEBUG : check sum: Unchanged skipping 2025/03/14 06:19:14 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-bebopij4liga': Waiting for transfers to finish 2025/03/14 06:19:14 DEBUG : Waiting for deletions to finish 2025/03/14 06:19:14 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-bebopij4liga'", Local "Local file system at /tmp/rclone492104059", Modify Window "1ms" --- PASS: TestSyncBasedOnCheckSum (4.62s) === RUN TestSyncSizeOnly run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-bebopij4liga'", Local "Local file system at /tmp/rclone492104059", Modify Window "1ms" 2025/03/14 06:19:17 DEBUG : sizeonly: Need to transfer - File not found at Destination 2025/03/14 06:19:17 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-bebopij4liga': Waiting for checks to finish 2025/03/14 06:19:17 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-bebopij4liga': Waiting for transfers to finish 2025/03/14 06:19:19 DEBUG : sizeonly: md5 = bf31ae8296355293d6d29cc04382e6ec OK 2025/03/14 06:19:19 INFO : sizeonly: Copied (new) 2025/03/14 06:19:19 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-bebopij4liga'", Local "Local file system at /tmp/rclone492104059", Modify Window "1ms" 2025/03/14 06:19:19 DEBUG : sizeonly: Sizes identical 2025/03/14 06:19:19 DEBUG : sizeonly: Unchanged skipping 2025/03/14 06:19:19 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-bebopij4liga': Waiting for checks to finish 2025/03/14 06:19:19 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-bebopij4liga': Waiting for transfers to finish 2025/03/14 06:19:19 DEBUG : Waiting for deletions to finish 2025/03/14 06:19:19 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-bebopij4liga'", Local "Local file system at /tmp/rclone492104059", Modify Window "1ms" --- PASS: TestSyncSizeOnly (4.41s) === RUN TestSyncIgnoreSize run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-bebopij4liga'", Local "Local file system at /tmp/rclone492104059", Modify Window "1ms" 2025/03/14 06:19:21 DEBUG : ignore-size: Need to transfer - File not found at Destination 2025/03/14 06:19:21 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-bebopij4liga': Waiting for checks to finish 2025/03/14 06:19:21 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-bebopij4liga': Waiting for transfers to finish 2025/03/14 06:19:23 DEBUG : ignore-size: md5 = 554055af9f099804b84b19ded2b703b4 OK 2025/03/14 06:19:23 INFO : ignore-size: Copied (new) 2025/03/14 06:19:23 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-bebopij4liga'", Local "Local file system at /tmp/rclone492104059", Modify Window "1ms" 2025/03/14 06:19:23 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-bebopij4liga': Waiting for checks to finish 2025/03/14 06:19:23 DEBUG : ignore-size: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/03/14 06:19:23 DEBUG : ignore-size: Unchanged skipping 2025/03/14 06:19:23 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-bebopij4liga': Waiting for transfers to finish 2025/03/14 06:19:23 DEBUG : Waiting for deletions to finish 2025/03/14 06:19:23 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-bebopij4liga'", Local "Local file system at /tmp/rclone492104059", Modify Window "1ms" --- PASS: TestSyncIgnoreSize (4.48s) === RUN TestSyncIgnoreTimes run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-bebopij4liga'", Local "Local file system at /tmp/rclone492104059", Modify Window "1ms" 2025/03/14 06:19:27 DEBUG : existing: md5 = 541b8514b6d072935dfc7696e57df72e OK 2025/03/14 06:19:28 DEBUG : existing: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/03/14 06:19:28 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-bebopij4liga': Waiting for checks to finish 2025/03/14 06:19:28 DEBUG : existing: Unchanged skipping 2025/03/14 06:19:28 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-bebopij4liga': Waiting for transfers to finish 2025/03/14 06:19:28 DEBUG : Waiting for deletions to finish 2025/03/14 06:19:28 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-bebopij4liga'", Local "Local file system at /tmp/rclone492104059", Modify Window "1ms" 2025/03/14 06:19:28 DEBUG : existing: Transferring unconditionally as --ignore-times is in use 2025/03/14 06:19:28 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-bebopij4liga': Waiting for checks to finish 2025/03/14 06:19:28 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-bebopij4liga': Waiting for transfers to finish 2025/03/14 06:19:29 DEBUG : existing: md5 = 762d3f35a64fc3c56d405ddd25f1ac81 OK 2025/03/14 06:19:29 INFO : existing: Copied (replaced existing) 2025/03/14 06:19:29 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-bebopij4liga'", Local "Local file system at /tmp/rclone492104059", Modify Window "1ms" --- PASS: TestSyncIgnoreTimes (5.55s) === RUN TestSyncIgnoreExisting run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-bebopij4liga'", Local "Local file system at /tmp/rclone492104059", Modify Window "1ms" 2025/03/14 06:19:31 DEBUG : existing: Need to transfer - File not found at Destination 2025/03/14 06:19:31 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-bebopij4liga': Waiting for checks to finish 2025/03/14 06:19:31 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-bebopij4liga': Waiting for transfers to finish 2025/03/14 06:19:33 DEBUG : existing: md5 = 25f0e1e3f820a8b30c72ff22fb52e968 OK 2025/03/14 06:19:33 INFO : existing: Copied (new) 2025/03/14 06:19:33 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-bebopij4liga'", Local "Local file system at /tmp/rclone492104059", Modify Window "1ms" 2025/03/14 06:19:33 DEBUG : existing: Destination exists, skipping 2025/03/14 06:19:33 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-bebopij4liga': Waiting for checks to finish 2025/03/14 06:19:33 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-bebopij4liga': Waiting for transfers to finish 2025/03/14 06:19:33 DEBUG : Waiting for deletions to finish 2025/03/14 06:19:33 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-bebopij4liga'", Local "Local file system at /tmp/rclone492104059", Modify Window "1ms" --- PASS: TestSyncIgnoreExisting (4.46s) === RUN TestSyncIgnoreErrors run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-bebopij4liga'", Local "Local file system at /tmp/rclone492104059", Modify Window "1ms" 2025/03/14 06:19:38 DEBUG : b/potato: md5 = a89661582952da31765afd1dd0407b17 OK 2025/03/14 06:19:40 DEBUG : c/non empty space: md5 = 6c27c6e941e4115ab9a08ad2cdcf9ef9 OK 2025/03/14 06:19:40 INFO : d: Making directory 2025/03/14 06:19:41 DEBUG : Added delayed dir = "a", newDst= 2025/03/14 06:19:42 INFO : c: Set directory modification time (using SetModTime) 2025/03/14 06:19:42 DEBUG : Added delayed dir = "c", newDst=c 2025/03/14 06:19:42 DEBUG : a/potato2: Need to transfer - File not found at Destination 2025/03/14 06:19:42 DEBUG : c/non empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/03/14 06:19:42 DEBUG : c/non empty space: Unchanged skipping 2025/03/14 06:19:42 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-bebopij4liga': Waiting for checks to finish 2025/03/14 06:19:42 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-bebopij4liga': Waiting for transfers to finish 2025/03/14 06:19:44 DEBUG : a/potato2: md5 = 6f2962f125c5f0c89f7c82a94ad66dae OK 2025/03/14 06:19:44 INFO : a/potato2: Copied (new) 2025/03/14 06:19:44 DEBUG : Waiting for deletions to finish 2025/03/14 06:19:44 INFO : b/potato: Deleted 2025/03/14 06:19:45 INFO : a: Set directory modification time (using DirSetModTime) 2025/03/14 06:19:45 INFO : d: Removing directory 2025/03/14 06:19:46 INFO : b: Removing directory 2025/03/14 06:19:46 DEBUG : 32d8ua6196mc1r7qkfog53rkg0: Rmdir: contains trashed file: "2m507n64kafsi59v9q71r281a4" 2025/03/14 06:19:46 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-bebopij4liga': deleted 2 directories run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-bebopij4liga'", Local "Local file system at /tmp/rclone492104059", Modify Window "1ms" 2025/03/14 06:19:49 DEBUG : 3i9du405pfogq3ncai6pg7ouio: Rmdir: contains trashed file: "982d3pss7t5pn0il16r2foj31s" 2025/03/14 06:19:49 DEBUG : 2bsvlrk2ne1lfitm6tttcu0qt8: Rmdir: contains trashed file: "89l8renevh3mji1c8r1p7qn6tg" --- PASS: TestSyncIgnoreErrors (14.92s) === RUN TestSyncAfterChangingModtimeOnly run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-bebopij4liga'", Local "Local file system at /tmp/rclone492104059", Modify Window "1ms" 2025/03/14 06:19:52 DEBUG : empty space: md5 = 9b64e077b80aa62bf9f04401f87a804c OK 2025/03/14 06:19:53 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-bebopij4liga': Waiting for checks to finish 2025/03/14 06:19:53 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/03/14 06:19:53 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-bebopij4liga': Waiting for transfers to finish 2025/03/14 06:19:53 NOTICE: empty space: Skipped copy as --dry-run is set (size 1) 2025/03/14 06:19:53 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-bebopij4liga'", Local "Local file system at /tmp/rclone492104059", Modify Window "1ms" 2025/03/14 06:19:53 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-bebopij4liga': Waiting for checks to finish 2025/03/14 06:19:53 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/03/14 06:19:53 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-bebopij4liga': Waiting for transfers to finish 2025/03/14 06:19:54 DEBUG : empty space: md5 = 8ca1ef049cc460b417b9172247cbe63b OK 2025/03/14 06:19:54 INFO : empty space: Copied (replaced existing) 2025/03/14 06:19:54 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-bebopij4liga'", Local "Local file system at /tmp/rclone492104059", Modify Window "1ms" --- PASS: TestSyncAfterChangingModtimeOnly (6.08s) === RUN TestSyncAfterChangingModtimeOnlyWithNoUpdateModTime run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-bebopij4liga'", Local "Local file system at /tmp/rclone492104059", Modify Window "1ms" sync_test.go:1016: Can't check this if no hashes supported --- PASS: TestSyncAfterChangingModtimeOnlyWithNoUpdateModTime (0.48s) === RUN TestSyncDoesntUpdateModtime run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-bebopij4liga'", Local "Local file system at /tmp/rclone492104059", Modify Window "1ms" 2025/03/14 06:19:59 DEBUG : foo: md5 = c3681ce99b27413568aee4ebc30cf54e OK 2025/03/14 06:19:59 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-bebopij4liga': Waiting for checks to finish 2025/03/14 06:19:59 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/03/14 06:19:59 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-bebopij4liga': Waiting for transfers to finish 2025/03/14 06:20:00 DEBUG : foo: md5 = aefefeca222c0e97a708a4bc2269153f OK 2025/03/14 06:20:00 INFO : foo: Copied (replaced existing) 2025/03/14 06:20:00 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-bebopij4liga'", Local "Local file system at /tmp/rclone492104059", Modify Window "1ms" --- PASS: TestSyncDoesntUpdateModtime (4.97s) === RUN TestSyncAfterAddingAFile run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-bebopij4liga'", Local "Local file system at /tmp/rclone492104059", Modify Window "1ms" 2025/03/14 06:20:03 DEBUG : empty space: md5 = b245de19b3a217672a4b25c5eab18279 OK 2025/03/14 06:20:04 DEBUG : potato: Need to transfer - File not found at Destination 2025/03/14 06:20:04 DEBUG : empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/03/14 06:20:04 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-bebopij4liga': Waiting for checks to finish 2025/03/14 06:20:04 DEBUG : empty space: Unchanged skipping 2025/03/14 06:20:04 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-bebopij4liga': Waiting for transfers to finish 2025/03/14 06:20:05 DEBUG : potato: md5 = 650d4557981a0e7cd06198e3e7da4904 OK 2025/03/14 06:20:05 INFO : potato: Copied (new) 2025/03/14 06:20:05 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-bebopij4liga'", Local "Local file system at /tmp/rclone492104059", Modify Window "1ms" --- PASS: TestSyncAfterAddingAFile (5.38s) === RUN TestSyncAfterChangingFilesSizeOnly run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-bebopij4liga'", Local "Local file system at /tmp/rclone492104059", Modify Window "1ms" 2025/03/14 06:20:09 DEBUG : potato: md5 = 40f2ce0ecfe76e34479aa3d146952fb4 OK 2025/03/14 06:20:09 DEBUG : potato: Sizes differ (src 21 vs dst 60) 2025/03/14 06:20:09 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-bebopij4liga': Waiting for checks to finish 2025/03/14 06:20:09 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-bebopij4liga': Waiting for transfers to finish 2025/03/14 06:20:10 DEBUG : potato: md5 = d40f94e3fae1ec39089bf42114ac1937 OK 2025/03/14 06:20:10 INFO : potato: Copied (replaced existing) 2025/03/14 06:20:10 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-bebopij4liga'", Local "Local file system at /tmp/rclone492104059", Modify Window "1ms" --- PASS: TestSyncAfterChangingFilesSizeOnly (4.80s) === RUN TestSyncAfterChangingContentsOnly run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-bebopij4liga'", Local "Local file system at /tmp/rclone492104059", Modify Window "1ms" 2025/03/14 06:20:14 DEBUG : potato: md5 = a955134a5399d01414804a64b5c9e446 OK 2025/03/14 06:20:14 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-bebopij4liga': Waiting for checks to finish 2025/03/14 06:20:14 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/03/14 06:20:14 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-bebopij4liga': Waiting for transfers to finish 2025/03/14 06:20:15 DEBUG : potato: md5 = b739126f8763083e40b4abbbd5a5049b OK 2025/03/14 06:20:15 INFO : potato: Copied (replaced existing) 2025/03/14 06:20:15 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-bebopij4liga'", Local "Local file system at /tmp/rclone492104059", Modify Window "1ms" --- PASS: TestSyncAfterChangingContentsOnly (4.93s) === RUN TestSyncAfterRemovingAFileAndAddingAFileDryRun run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-bebopij4liga'", Local "Local file system at /tmp/rclone492104059", Modify Window "1ms" 2025/03/14 06:20:19 DEBUG : potato: md5 = f4bac79f74c3152313a4d0fd5d03af1c OK 2025/03/14 06:20:20 DEBUG : empty space: md5 = 745082cadf37ee91eca193e20a002748 OK 2025/03/14 06:20:20 DEBUG : potato2: Need to transfer - File not found at Destination 2025/03/14 06:20:20 DEBUG : empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/03/14 06:20:20 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-bebopij4liga': Waiting for checks to finish 2025/03/14 06:20:20 DEBUG : empty space: Unchanged skipping 2025/03/14 06:20:20 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-bebopij4liga': Waiting for transfers to finish 2025/03/14 06:20:20 NOTICE: potato2: Skipped copy as --dry-run is set (size 60) 2025/03/14 06:20:20 DEBUG : Waiting for deletions to finish 2025/03/14 06:20:20 NOTICE: potato: Skipped delete as --dry-run is set (size 21) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-bebopij4liga'", Local "Local file system at /tmp/rclone492104059", Modify Window "1ms" --- PASS: TestSyncAfterRemovingAFileAndAddingAFileDryRun (5.15s) === RUN TestSyncAfterRemovingAFileAndAddingAFile run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-bebopij4liga'", Local "Local file system at /tmp/rclone492104059", Modify Window "1ms" 2025/03/14 06:20:24 DEBUG : potato: md5 = d0d4e074e100564d69598d6784a236a5 OK 2025/03/14 06:20:25 DEBUG : empty space: md5 = a904cb38d14a4850b024f76309ea95ac OK 2025/03/14 06:20:26 DEBUG : potato2: Need to transfer - File not found at Destination 2025/03/14 06:20:26 DEBUG : empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/03/14 06:20:26 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-bebopij4liga': Waiting for checks to finish 2025/03/14 06:20:26 DEBUG : empty space: Unchanged skipping 2025/03/14 06:20:26 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-bebopij4liga': Waiting for transfers to finish 2025/03/14 06:20:27 DEBUG : potato2: md5 = 087642d3422ead0d014cfc7e88e56d5a OK 2025/03/14 06:20:27 INFO : potato2: Copied (new) 2025/03/14 06:20:27 DEBUG : Waiting for deletions to finish 2025/03/14 06:20:27 INFO : potato: Deleted run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-bebopij4liga'", Local "Local file system at /tmp/rclone492104059", Modify Window "1ms" --- PASS: TestSyncAfterRemovingAFileAndAddingAFile (7.22s) === RUN TestSyncAfterRemovingAFileAndAddingAFileSubDir run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-bebopij4liga'", Local "Local file system at /tmp/rclone492104059", Modify Window "1ms" 2025/03/14 06:20:32 DEBUG : b/potato: md5 = 392f3b098435f87b1b664f971c50aae2 OK 2025/03/14 06:20:34 DEBUG : c/non empty space: md5 = 041096a7f6f74b782fd3b0a27bba4169 OK 2025/03/14 06:20:34 INFO : d: Making directory 2025/03/14 06:20:35 INFO : d/e: Making directory 2025/03/14 06:20:37 DEBUG : Added delayed dir = "a", newDst= 2025/03/14 06:20:37 INFO : c: Set directory modification time (using SetModTime) 2025/03/14 06:20:37 DEBUG : Added delayed dir = "c", newDst=c 2025/03/14 06:20:37 DEBUG : a/potato2: Need to transfer - File not found at Destination 2025/03/14 06:20:38 DEBUG : c/non empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/03/14 06:20:38 DEBUG : c/non empty space: Unchanged skipping 2025/03/14 06:20:39 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-bebopij4liga': Waiting for checks to finish 2025/03/14 06:20:39 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-bebopij4liga': Waiting for transfers to finish 2025/03/14 06:20:40 DEBUG : a/potato2: md5 = 7c9cc561a38ff37f7dc0a30ce8e1f9a1 OK 2025/03/14 06:20:40 INFO : a/potato2: Copied (new) 2025/03/14 06:20:40 DEBUG : Waiting for deletions to finish 2025/03/14 06:20:40 INFO : b/potato: Deleted 2025/03/14 06:20:40 INFO : a: Set directory modification time (using DirSetModTime) 2025/03/14 06:20:40 INFO : d/e: Removing directory 2025/03/14 06:20:41 INFO : d: Removing directory 2025/03/14 06:20:41 DEBUG : ka6id8d20d3s5ktapedlphgta8: Rmdir: contains trashed file: "r8sppajuabeak3sbgj2ak8vuf8" 2025/03/14 06:20:42 INFO : b: Removing directory 2025/03/14 06:20:42 DEBUG : 32d8ua6196mc1r7qkfog53rkg0: Rmdir: contains trashed file: "2m507n64kafsi59v9q71r281a4" 2025/03/14 06:20:43 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-bebopij4liga': deleted 3 directories run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-bebopij4liga'", Local "Local file system at /tmp/rclone492104059", Modify Window "1ms" 2025/03/14 06:20:45 DEBUG : 3i9du405pfogq3ncai6pg7ouio: Rmdir: contains trashed file: "982d3pss7t5pn0il16r2foj31s" 2025/03/14 06:20:45 DEBUG : 2bsvlrk2ne1lfitm6tttcu0qt8: Rmdir: contains trashed file: "89l8renevh3mji1c8r1p7qn6tg" --- PASS: TestSyncAfterRemovingAFileAndAddingAFileSubDir (17.05s) === RUN TestSyncAfterRemovingAFileAndAddingAFileSubDirWithErrors run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-bebopij4liga'", Local "Local file system at /tmp/rclone492104059", Modify Window "1ms" 2025/03/14 06:20:49 DEBUG : b/potato: md5 = bb1c51b56d954c4a51c6bb9f6fe6284c OK 2025/03/14 06:20:51 DEBUG : c/non empty space: md5 = 520204db4ca202c7e4bb0153ca9cd63a OK 2025/03/14 06:20:51 INFO : d: Making directory 2025/03/14 06:20:52 DEBUG : Added delayed dir = "a", newDst= 2025/03/14 06:20:53 INFO : c: Set directory modification time (using SetModTime) 2025/03/14 06:20:53 DEBUG : Added delayed dir = "c", newDst=c 2025/03/14 06:20:53 DEBUG : a/potato2: Need to transfer - File not found at Destination 2025/03/14 06:20:53 DEBUG : c/non empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/03/14 06:20:53 DEBUG : c/non empty space: Unchanged skipping 2025/03/14 06:20:53 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-bebopij4liga': Waiting for checks to finish 2025/03/14 06:20:53 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-bebopij4liga': Waiting for transfers to finish 2025/03/14 06:20:55 DEBUG : a/potato2: md5 = 9570fec613f14c7fa397989bc9ecf55d OK 2025/03/14 06:20:55 INFO : a/potato2: Copied (new) 2025/03/14 06:20:55 ERROR : Encrypted drive 'TestCryptDrive:rclone-test-bebopij4liga': not deleting files as there were IO errors 2025/03/14 06:20:56 INFO : a: Set directory modification time (using DirSetModTime) 2025/03/14 06:20:56 ERROR : Encrypted drive 'TestCryptDrive:rclone-test-bebopij4liga': not deleting directories as there were IO errors run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-bebopij4liga'", Local "Local file system at /tmp/rclone492104059", Modify Window "1ms" 2025/03/14 06:20:59 DEBUG : 3i9du405pfogq3ncai6pg7ouio: Rmdir: contains trashed file: "982d3pss7t5pn0il16r2foj31s" 2025/03/14 06:21:00 DEBUG : 32d8ua6196mc1r7qkfog53rkg0: Rmdir: contains trashed file: "2m507n64kafsi59v9q71r281a4" 2025/03/14 06:21:01 DEBUG : 2bsvlrk2ne1lfitm6tttcu0qt8: Rmdir: contains trashed file: "89l8renevh3mji1c8r1p7qn6tg" --- PASS: TestSyncAfterRemovingAFileAndAddingAFileSubDirWithErrors (15.11s) === RUN TestSyncDeleteAfter --- PASS: TestSyncDeleteAfter (0.00s) === RUN TestSyncDeleteDuring run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-bebopij4liga'", Local "Local file system at /tmp/rclone492104059", Modify Window "1ms" 2025/03/14 06:21:03 DEBUG : potato: md5 = 975c77ff53ce767aa41fce55701155d6 OK 2025/03/14 06:21:04 DEBUG : empty space: md5 = 2137091168a0408a18c13f730f23c784 OK 2025/03/14 06:21:05 DEBUG : Waiting for deletions to finish 2025/03/14 06:21:05 DEBUG : potato2: Need to transfer - File not found at Destination 2025/03/14 06:21:05 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-bebopij4liga': Waiting for checks to finish 2025/03/14 06:21:05 DEBUG : empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/03/14 06:21:05 DEBUG : empty space: Unchanged skipping 2025/03/14 06:21:05 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-bebopij4liga': Waiting for transfers to finish 2025/03/14 06:21:05 INFO : potato: Deleted 2025/03/14 06:21:06 DEBUG : potato2: md5 = 82284983961d2b49c71e76421f03aeee OK 2025/03/14 06:21:06 INFO : potato2: Copied (new) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-bebopij4liga'", Local "Local file system at /tmp/rclone492104059", Modify Window "1ms" --- PASS: TestSyncDeleteDuring (6.93s) === RUN TestSyncDeleteBefore run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-bebopij4liga'", Local "Local file system at /tmp/rclone492104059", Modify Window "1ms" 2025/03/14 06:21:10 DEBUG : potato: md5 = 13cbde9349ce85e54af362fc68a8ce30 OK 2025/03/14 06:21:11 DEBUG : empty space: md5 = 030e066a8ace461cdfd961f854b344a7 OK 2025/03/14 06:21:12 DEBUG : Waiting for deletions to finish 2025/03/14 06:21:12 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-bebopij4liga': Waiting for checks to finish 2025/03/14 06:21:12 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-bebopij4liga': Waiting for transfers to finish 2025/03/14 06:21:12 INFO : potato: Deleted 2025/03/14 06:21:13 DEBUG : potato2: Need to transfer - File not found at Destination 2025/03/14 06:21:13 DEBUG : empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/03/14 06:21:13 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-bebopij4liga': Waiting for checks to finish 2025/03/14 06:21:13 DEBUG : empty space: Unchanged skipping 2025/03/14 06:21:13 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-bebopij4liga': Waiting for transfers to finish 2025/03/14 06:21:14 DEBUG : potato2: md5 = db2b77b0667bf55c79d779bbaea958cd OK 2025/03/14 06:21:14 INFO : potato2: Copied (new) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-bebopij4liga'", Local "Local file system at /tmp/rclone492104059", Modify Window "1ms" --- PASS: TestSyncDeleteBefore (7.74s) === RUN TestCopyDeleteBefore run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-bebopij4liga'", Local "Local file system at /tmp/rclone492104059", Modify Window "1ms" 2025/03/14 06:21:18 DEBUG : potato: md5 = d428f68b2f9fed311a9ec737ebde4777 OK 2025/03/14 06:21:18 DEBUG : potato2: Need to transfer - File not found at Destination 2025/03/14 06:21:18 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-bebopij4liga': Waiting for checks to finish 2025/03/14 06:21:18 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-bebopij4liga': Waiting for transfers to finish 2025/03/14 06:21:20 DEBUG : potato2: md5 = 520d7613c56a25dd56a4ecdc4c530a78 OK 2025/03/14 06:21:20 INFO : potato2: Copied (new) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-bebopij4liga'", Local "Local file system at /tmp/rclone492104059", Modify Window "1ms" --- PASS: TestCopyDeleteBefore (5.43s) === RUN TestSyncWithExclude run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-bebopij4liga'", Local "Local file system at /tmp/rclone492104059", Modify Window "1ms" 2025/03/14 06:21:23 DEBUG : potato2: md5 = 9c068f119447d4780e933978d3ca3008 OK 2025/03/14 06:21:24 DEBUG : empty space: md5 = 9a3174696c737426f2e67b46d4f9878e OK 2025/03/14 06:21:25 DEBUG : enormous: Excluded (Size Filter) 2025/03/14 06:21:25 DEBUG : enormous: Excluded 2025/03/14 06:21:25 DEBUG : potato2: Excluded (Size Filter) 2025/03/14 06:21:25 DEBUG : potato2: Excluded 2025/03/14 06:21:25 DEBUG : potato2: Excluded (Size Filter) 2025/03/14 06:21:25 DEBUG : potato2: Excluded 2025/03/14 06:21:25 DEBUG : empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/03/14 06:21:25 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-bebopij4liga': Waiting for checks to finish 2025/03/14 06:21:25 DEBUG : empty space: Unchanged skipping 2025/03/14 06:21:25 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-bebopij4liga': Waiting for transfers to finish 2025/03/14 06:21:25 DEBUG : Waiting for deletions to finish 2025/03/14 06:21:25 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-bebopij4liga'", Local "Local file system at /tmp/rclone492104059", Modify Window "1ms" 2025/03/14 06:21:25 DEBUG : enormous: Excluded (Size Filter) 2025/03/14 06:21:25 DEBUG : enormous: Excluded 2025/03/14 06:21:25 DEBUG : potato2: Excluded (Size Filter) 2025/03/14 06:21:25 DEBUG : potato2: Excluded 2025/03/14 06:21:26 DEBUG : potato2: Excluded (Size Filter) 2025/03/14 06:21:26 DEBUG : potato2: Excluded 2025/03/14 06:21:26 DEBUG : empty space: Size and modification time the same (differ by 456.789µs, within tolerance 1ms) 2025/03/14 06:21:26 DEBUG : empty space: Unchanged skipping 2025/03/14 06:21:26 DEBUG : Local file system at /tmp/rclone492104059: Waiting for checks to finish 2025/03/14 06:21:26 DEBUG : Local file system at /tmp/rclone492104059: Waiting for transfers to finish 2025/03/14 06:21:26 DEBUG : Waiting for deletions to finish 2025/03/14 06:21:26 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-bebopij4liga'", Local "Local file system at /tmp/rclone492104059", Modify Window "1ms" --- PASS: TestSyncWithExclude (6.08s) === RUN TestSyncWithExcludeAndDeleteExcluded run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-bebopij4liga'", Local "Local file system at /tmp/rclone492104059", Modify Window "1ms" 2025/03/14 06:21:29 DEBUG : potato2: md5 = 600b3ed6a5aaefcaca048ddf58b65be8 OK 2025/03/14 06:21:31 DEBUG : empty space: md5 = 7a20823ddb018d9278e4b979503125ba OK 2025/03/14 06:21:32 DEBUG : enormous: md5 = c557dabae54e168205399b01e5fd1a23 OK 2025/03/14 06:21:33 DEBUG : enormous: Excluded (Size Filter) 2025/03/14 06:21:33 DEBUG : enormous: Excluded 2025/03/14 06:21:33 DEBUG : potato2: Excluded (Size Filter) 2025/03/14 06:21:33 DEBUG : potato2: Excluded 2025/03/14 06:21:33 DEBUG : empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/03/14 06:21:33 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-bebopij4liga': Waiting for checks to finish 2025/03/14 06:21:33 DEBUG : empty space: Unchanged skipping 2025/03/14 06:21:33 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-bebopij4liga': Waiting for transfers to finish 2025/03/14 06:21:33 DEBUG : Waiting for deletions to finish 2025/03/14 06:21:33 INFO : potato2: Deleted 2025/03/14 06:21:33 INFO : enormous: Deleted 2025/03/14 06:21:33 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-bebopij4liga'", Local "Local file system at /tmp/rclone492104059", Modify Window "1ms" 2025/03/14 06:21:34 DEBUG : Local file system at /tmp/rclone492104059: Waiting for checks to finish 2025/03/14 06:21:34 DEBUG : empty space: Size and modification time the same (differ by 456.789µs, within tolerance 1ms) 2025/03/14 06:21:34 DEBUG : empty space: Unchanged skipping 2025/03/14 06:21:34 DEBUG : Local file system at /tmp/rclone492104059: Waiting for transfers to finish 2025/03/14 06:21:34 DEBUG : Waiting for deletions to finish 2025/03/14 06:21:34 INFO : enormous: Deleted 2025/03/14 06:21:34 INFO : potato2: Deleted 2025/03/14 06:21:34 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-bebopij4liga'", Local "Local file system at /tmp/rclone492104059", Modify Window "1ms" --- PASS: TestSyncWithExcludeAndDeleteExcluded (7.79s) === RUN TestSyncWithUpdateOlder run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-bebopij4liga'", Local "Local file system at /tmp/rclone492104059", Modify Window "1ms" 2025/03/14 06:21:37 DEBUG : one: md5 = c7c9f36e0fa5421d90a8e9b5b8092c50 OK 2025/03/14 06:21:38 DEBUG : two: md5 = 30657d5577f8bcc60322b8eb25d0a7c7 OK 2025/03/14 06:21:40 DEBUG : three: md5 = b7d84553c90afa1410a23e838b72f830 OK 2025/03/14 06:21:41 DEBUG : four: md5 = 15a204d5a36d2faad5d53b493961fbbe OK 2025/03/14 06:21:42 DEBUG : five: Need to transfer - File not found at Destination 2025/03/14 06:21:42 DEBUG : four: Sizes differ (src 4 vs dst 8) 2025/03/14 06:21:42 DEBUG : one: Destination is newer than source, skipping 2025/03/14 06:21:42 DEBUG : three: Sizes identical 2025/03/14 06:21:42 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-bebopij4liga': Waiting for checks to finish 2025/03/14 06:21:42 DEBUG : four: Destination mod time is within 1s of source but files differ, transferring 2025/03/14 06:21:42 DEBUG : three: Destination mod time is within 1s of source and files identical, skipping 2025/03/14 06:21:42 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-bebopij4liga': Waiting for transfers to finish 2025/03/14 06:21:43 DEBUG : two: md5 = 661195739cacfe91aa72adb05f423dc4 OK 2025/03/14 06:21:43 INFO : two: Copied (replaced existing) 2025/03/14 06:21:43 DEBUG : four: md5 = 127e0d0f19932f31db388a69fc585342 OK 2025/03/14 06:21:43 INFO : four: Copied (replaced existing) 2025/03/14 06:21:43 DEBUG : five: md5 = 893799f39686271b52d6d5b9694b6d08 OK 2025/03/14 06:21:43 INFO : five: Copied (new) 2025/03/14 06:21:43 DEBUG : Waiting for deletions to finish sync_test.go:1449: Skip test with --checksum as no hashes supported --- PASS: TestSyncWithUpdateOlder (10.54s) === 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-bebopij4liga'", Local "Local file system at /tmp/rclone492104059", Modify Window "1ms" sync_test.go:1538: Can track renames: false 2025/03/14 06:21:46 ERROR : Encrypted drive 'TestCryptDrive:rclone-test-bebopij4liga': Ignoring --track-renames as the source and destination do not have a common hash 2025/03/14 06:21:46 DEBUG : potato: Need to transfer - File not found at Destination 2025/03/14 06:21:46 DEBUG : yam: Need to transfer - File not found at Destination 2025/03/14 06:21:46 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-bebopij4liga': Waiting for checks to finish 2025/03/14 06:21:46 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-bebopij4liga': Waiting for transfers to finish 2025/03/14 06:21:48 DEBUG : yam: md5 = f1c192b0bca073b3e323dd6028bcf119 OK 2025/03/14 06:21:48 INFO : yam: Copied (new) 2025/03/14 06:21:48 DEBUG : potato: md5 = 01c90e3d8a3d8094082abaef5f1cdca1 OK 2025/03/14 06:21:48 INFO : potato: Copied (new) 2025/03/14 06:21:48 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-bebopij4liga'", Local "Local file system at /tmp/rclone492104059", Modify Window "1ms" 2025/03/14 06:21:48 ERROR : Encrypted drive 'TestCryptDrive:rclone-test-bebopij4liga': Ignoring --track-renames as the source and destination do not have a common hash 2025/03/14 06:21:48 DEBUG : yaml: Need to transfer - File not found at Destination 2025/03/14 06:21:48 DEBUG : potato: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/03/14 06:21:48 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-bebopij4liga': Waiting for checks to finish 2025/03/14 06:21:48 DEBUG : potato: Unchanged skipping 2025/03/14 06:21:48 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-bebopij4liga': Waiting for transfers to finish 2025/03/14 06:21:50 DEBUG : yaml: md5 = c4e665a9b85d890db03c0a2f8857f818 OK 2025/03/14 06:21:50 INFO : yaml: Copied (new) 2025/03/14 06:21:50 DEBUG : Waiting for deletions to finish 2025/03/14 06:21:50 INFO : yam: Deleted run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-bebopij4liga'", Local "Local file system at /tmp/rclone492104059", Modify Window "1ms" --- PASS: TestSyncWithTrackRenames (6.49s) === RUN TestParseRenamesStrategyModtime --- PASS: TestParseRenamesStrategyModtime (0.00s) === RUN TestRenamesStrategyModtime --- PASS: TestRenamesStrategyModtime (0.00s) === RUN TestSyncWithTrackRenamesStrategyModtime run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-bebopij4liga'", Local "Local file system at /tmp/rclone492104059", Modify Window "1ms" sync_test.go:1610: Can track renames: true 2025/03/14 06:21:53 INFO : Encrypted drive 'TestCryptDrive:rclone-test-bebopij4liga': Making map for --track-renames 2025/03/14 06:21:53 INFO : Encrypted drive 'TestCryptDrive:rclone-test-bebopij4liga': Finished making map for --track-renames 2025/03/14 06:21:53 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-bebopij4liga': Waiting for checks to finish 2025/03/14 06:21:53 DEBUG : potato: Need to transfer - No matching file found at Destination 2025/03/14 06:21:53 DEBUG : yam: Need to transfer - No matching file found at Destination 2025/03/14 06:21:53 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-bebopij4liga': Waiting for renames to finish 2025/03/14 06:21:53 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-bebopij4liga': Waiting for transfers to finish 2025/03/14 06:21:54 DEBUG : yam: md5 = 9df6ae95a2db799c88cfc314fb89f763 OK 2025/03/14 06:21:54 INFO : yam: Copied (new) 2025/03/14 06:21:54 DEBUG : potato: md5 = 6444213ba3c404452727ed0256910663 OK 2025/03/14 06:21:54 INFO : potato: Copied (new) 2025/03/14 06:21:54 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-bebopij4liga'", Local "Local file system at /tmp/rclone492104059", Modify Window "1ms" 2025/03/14 06:21:55 DEBUG : potato: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/03/14 06:21:55 INFO : Encrypted drive 'TestCryptDrive:rclone-test-bebopij4liga': Making map for --track-renames 2025/03/14 06:21:55 INFO : Encrypted drive 'TestCryptDrive:rclone-test-bebopij4liga': Finished making map for --track-renames 2025/03/14 06:21:55 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-bebopij4liga': Waiting for checks to finish 2025/03/14 06:21:55 DEBUG : potato: Unchanged skipping 2025/03/14 06:21:55 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-bebopij4liga': Waiting for renames to finish 2025/03/14 06:21:56 INFO : yam: Moved (server-side) to: yaml 2025/03/14 06:21:56 INFO : yaml: Renamed from "yam" 2025/03/14 06:21:56 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-bebopij4liga': Waiting for transfers to finish 2025/03/14 06:21:56 DEBUG : Waiting for deletions to finish 2025/03/14 06:21:56 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-bebopij4liga'", Local "Local file system at /tmp/rclone492104059", Modify Window "1ms" --- PASS: TestSyncWithTrackRenamesStrategyModtime (5.50s) === RUN TestSyncWithTrackRenamesStrategyLeaf run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-bebopij4liga'", Local "Local file system at /tmp/rclone492104059", Modify Window "1ms" sync_test.go:1649: Can track renames: true 2025/03/14 06:21:58 DEBUG : Added delayed dir = "sub", newDst= 2025/03/14 06:21:58 INFO : Encrypted drive 'TestCryptDrive:rclone-test-bebopij4liga': Making map for --track-renames 2025/03/14 06:21:58 INFO : Encrypted drive 'TestCryptDrive:rclone-test-bebopij4liga': Finished making map for --track-renames 2025/03/14 06:21:58 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-bebopij4liga': Waiting for checks to finish 2025/03/14 06:21:58 DEBUG : potato: Need to transfer - No matching file found at Destination 2025/03/14 06:21:58 DEBUG : sub/yam: Need to transfer - No matching file found at Destination 2025/03/14 06:21:58 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-bebopij4liga': Waiting for renames to finish 2025/03/14 06:21:58 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-bebopij4liga': Waiting for transfers to finish 2025/03/14 06:22:01 DEBUG : potato: md5 = f01a2437ab5acacea7a734b135b4137b OK 2025/03/14 06:22:01 INFO : potato: Copied (new) 2025/03/14 06:22:01 DEBUG : sub/yam: md5 = 3fbe934a135919d004fdb16eebf1cfa3 OK 2025/03/14 06:22:01 INFO : sub/yam: Copied (new) 2025/03/14 06:22:01 DEBUG : Waiting for deletions to finish 2025/03/14 06:22:01 INFO : sub: Set directory modification time (using DirSetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-bebopij4liga'", Local "Local file system at /tmp/rclone492104059", Modify Window "1ms" 2025/03/14 06:22:02 DEBUG : potato: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/03/14 06:22:02 DEBUG : potato: Unchanged skipping 2025/03/14 06:22:02 INFO : sub: Set directory modification time (using SetModTime) 2025/03/14 06:22:02 DEBUG : Added delayed dir = "sub", newDst=sub 2025/03/14 06:22:03 INFO : Encrypted drive 'TestCryptDrive:rclone-test-bebopij4liga': Making map for --track-renames 2025/03/14 06:22:03 INFO : Encrypted drive 'TestCryptDrive:rclone-test-bebopij4liga': Finished making map for --track-renames 2025/03/14 06:22:03 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-bebopij4liga': Waiting for checks to finish 2025/03/14 06:22:03 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-bebopij4liga': Waiting for renames to finish 2025/03/14 06:22:03 INFO : sub/yam: Moved (server-side) to: yam 2025/03/14 06:22:03 INFO : yam: Renamed from "sub/yam" 2025/03/14 06:22:03 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-bebopij4liga': Waiting for transfers to finish 2025/03/14 06:22:03 DEBUG : Waiting for deletions to finish 2025/03/14 06:22:03 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-bebopij4liga'", Local "Local file system at /tmp/rclone492104059", Modify Window "1ms" --- PASS: TestSyncWithTrackRenamesStrategyLeaf (9.04s) === RUN TestServerSideMoveLocal run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-bebopij4liga'", Local "Local file system at /tmp/rclone492104059", Modify Window "1ms" 2025/03/14 06:22:07 DEBUG : Creating backend with remote "/tmp/rclone492104059/dir1" 2025/03/14 06:22:07 DEBUG : Creating backend with remote "/tmp/rclone492104059/dir2" 2025/03/14 06:22:07 DEBUG : Local file system at /tmp/rclone492104059/dir2: Using server-side directory move 2025/03/14 06:22:07 INFO : Local file system at /tmp/rclone492104059/dir2: Server side directory move failed - fallback to file moves: can't copy directory - destination already exists 2025/03/14 06:22:07 DEBUG : file1.txt: Need to transfer - File not found at Destination 2025/03/14 06:22:07 INFO : file1.txt: Moved (server-side) 2025/03/14 06:22:07 DEBUG : Local file system at /tmp/rclone492104059/dir2: Waiting for checks to finish 2025/03/14 06:22:07 DEBUG : Local file system at /tmp/rclone492104059/dir2: Waiting for transfers to finish --- PASS: TestServerSideMoveLocal (0.46s) === RUN TestMoveWithDeleteEmptySrcDirs run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-bebopij4liga'", Local "Local file system at /tmp/rclone492104059", Modify Window "1ms" 2025/03/14 06:22:08 DEBUG : Added delayed dir = "nested", newDst= 2025/03/14 06:22:08 DEBUG : Added delayed dir = "sub dir", newDst= 2025/03/14 06:22:08 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2025/03/14 06:22:08 DEBUG : Added delayed dir = "nested/sub dir", newDst= 2025/03/14 06:22:08 DEBUG : nested/sub dir/file: Need to transfer - File not found at Destination 2025/03/14 06:22:08 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-bebopij4liga': Waiting for checks to finish 2025/03/14 06:22:08 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-bebopij4liga': Waiting for transfers to finish 2025/03/14 06:22:10 DEBUG : sub dir/hello world: md5 = 8ad3fb34934184c4a95c6e49f26b0040 OK 2025/03/14 06:22:10 INFO : sub dir/hello world: Copied (new) 2025/03/14 06:22:10 INFO : sub dir/hello world: Deleted 2025/03/14 06:22:12 DEBUG : nested/sub dir/file: md5 = fe6f3b19603ddfe4b7d20bc13cb7a0d1 OK 2025/03/14 06:22:12 INFO : nested/sub dir/file: Copied (new) 2025/03/14 06:22:12 INFO : nested/sub dir/file: Deleted 2025/03/14 06:22:12 INFO : nested/sub dir: Set directory modification time (using DirSetModTime) 2025/03/14 06:22:13 INFO : sub dir: Set directory modification time (using DirSetModTime) 2025/03/14 06:22:13 INFO : nested: Set directory modification time (using DirSetModTime) 2025/03/14 06:22:13 INFO : sub dir: Removing directory 2025/03/14 06:22:13 INFO : nested/sub dir: Removing directory 2025/03/14 06:22:13 INFO : nested: Removing directory 2025/03/14 06:22:13 DEBUG : Local file system at /tmp/rclone492104059: deleted 3 directories run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-bebopij4liga'", Local "Local file system at /tmp/rclone492104059", Modify Window "1ms" 2025/03/14 06:22:15 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" 2025/03/14 06:22:16 DEBUG : 37qp6d1gohacv723ij3brofbu8/14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "ftp4kuv8se7tqduu6pmmcvjsmk" 2025/03/14 06:22:17 DEBUG : 37qp6d1gohacv723ij3brofbu8: Rmdir: contains trashed file: "14begaa36ih249fgrnfk6nulg0" --- PASS: TestMoveWithDeleteEmptySrcDirs (10.37s) === RUN TestMoveWithoutDeleteEmptySrcDirs run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-bebopij4liga'", Local "Local file system at /tmp/rclone492104059", Modify Window "1ms" 2025/03/14 06:22:18 DEBUG : Added delayed dir = "nested", newDst= 2025/03/14 06:22:18 DEBUG : Added delayed dir = "sub dir", newDst= 2025/03/14 06:22:18 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2025/03/14 06:22:18 DEBUG : Added delayed dir = "nested/sub dir", newDst= 2025/03/14 06:22:18 DEBUG : nested/sub dir/file: Need to transfer - File not found at Destination 2025/03/14 06:22:18 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-bebopij4liga': Waiting for checks to finish 2025/03/14 06:22:18 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-bebopij4liga': Waiting for transfers to finish 2025/03/14 06:22:20 DEBUG : sub dir/hello world: md5 = 4b37249dca80e75b57c90372e3fea0a7 OK 2025/03/14 06:22:20 INFO : sub dir/hello world: Copied (new) 2025/03/14 06:22:20 INFO : sub dir/hello world: Deleted 2025/03/14 06:22:22 DEBUG : nested/sub dir/file: md5 = 521fa106a2ab120bea2914d3c7fbae71 OK 2025/03/14 06:22:22 INFO : nested/sub dir/file: Copied (new) 2025/03/14 06:22:22 INFO : nested/sub dir/file: Deleted 2025/03/14 06:22:23 INFO : nested/sub dir: Set directory modification time (using DirSetModTime) 2025/03/14 06:22:23 INFO : sub dir: Set directory modification time (using DirSetModTime) 2025/03/14 06:22:23 INFO : nested: Set directory modification time (using DirSetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-bebopij4liga'", Local "Local file system at /tmp/rclone492104059", Modify Window "1ms" 2025/03/14 06:22:26 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" 2025/03/14 06:22:27 DEBUG : 37qp6d1gohacv723ij3brofbu8/14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "ftp4kuv8se7tqduu6pmmcvjsmk" 2025/03/14 06:22:28 DEBUG : 37qp6d1gohacv723ij3brofbu8: Rmdir: contains trashed file: "14begaa36ih249fgrnfk6nulg0" --- PASS: TestMoveWithoutDeleteEmptySrcDirs (10.64s) === RUN TestMoveWithIgnoreExisting run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-bebopij4liga'", Local "Local file system at /tmp/rclone492104059", Modify Window "1ms" 2025/03/14 06:22:29 DEBUG : existing: Need to transfer - File not found at Destination 2025/03/14 06:22:29 DEBUG : existing-b: Need to transfer - File not found at Destination 2025/03/14 06:22:29 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-bebopij4liga': Waiting for checks to finish 2025/03/14 06:22:29 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-bebopij4liga': Waiting for transfers to finish 2025/03/14 06:22:30 DEBUG : existing: md5 = 0a03241255088ba15dc858f2c98b6d2b OK 2025/03/14 06:22:30 INFO : existing: Copied (new) 2025/03/14 06:22:30 INFO : existing: Deleted 2025/03/14 06:22:30 DEBUG : existing-b: md5 = f12943770e1c17797caa8fb1376f1e67 OK 2025/03/14 06:22:30 INFO : existing-b: Copied (new) 2025/03/14 06:22:30 INFO : existing-b: Deleted 2025/03/14 06:22:31 DEBUG : existing: Destination exists, skipping 2025/03/14 06:22:31 DEBUG : existing: Not removing source file as destination file exists and --ignore-existing is set 2025/03/14 06:22:31 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-bebopij4liga': Waiting for checks to finish 2025/03/14 06:22:31 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-bebopij4liga': Waiting for transfers to finish 2025/03/14 06:22:31 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-bebopij4liga'", Local "Local file system at /tmp/rclone492104059", Modify Window "1ms" --- PASS: TestMoveWithIgnoreExisting (4.39s) === RUN TestServerSideMove run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-bebopij4liga'", Local "Local file system at /tmp/rclone492104059", Modify Window "1ms" 2025/03/14 06:22:33 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-fobilac3cazu" 2025/03/14 06:22:33 DEBUG : Creating backend with remote "TestDrive:crypt/gr48offl6h5m4e1a7625d8sl5qb2ko37jon2m6ma09gs177qjc6g" 2025/03/14 06:22:36 DEBUG : potato2: md5 = 241619f514a904b62427198c2ca65069 OK 2025/03/14 06:22:37 DEBUG : empty space: md5 = 8f30bda68adbdb2a4c7a252ab2f21d9e OK 2025/03/14 06:22:38 DEBUG : potato3: md5 = 817ec46363262f99c76e590e844fae18 OK sync_test.go:1705: Server side move (if possible) Encrypted drive 'TestCryptDrive:rclone-test-bebopij4liga' -> Encrypted drive 'TestCryptDrive:rclone-test-fobilac3cazu' 2025/03/14 06:22:41 DEBUG : empty space: md5 = 328d60d49979812cc445b3bcef9ef2eb OK 2025/03/14 06:22:42 DEBUG : potato3: md5 = f77e97b625964bc50558070ae47025ca OK 2025/03/14 06:22:43 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-fobilac3cazu': Using server-side directory move 2025/03/14 06:22:43 INFO : Encrypted drive 'TestCryptDrive:rclone-test-fobilac3cazu': Server side directory move failed - fallback to file moves: can't copy directory - destination already exists 2025/03/14 06:22:43 DEBUG : potato2: Need to transfer - File not found at Destination 2025/03/14 06:22:43 DEBUG : empty space: Size and modification time the same (differ by 0s, within tolerance 1ms) 2025/03/14 06:22:43 DEBUG : empty space: Unchanged skipping 2025/03/14 06:22:43 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-fobilac3cazu': Waiting for checks to finish 2025/03/14 06:22:43 DEBUG : potato3: Sizes differ (src 68 vs dst 60) 2025/03/14 06:22:43 INFO : empty space: Deleted 2025/03/14 06:22:43 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-fobilac3cazu': Waiting for transfers to finish 2025/03/14 06:22:43 INFO : potato3: Deleted 2025/03/14 06:22:44 INFO : potato2: Moved (server-side) 2025/03/14 06:22:44 INFO : potato3: Moved (server-side) 2025/03/14 06:22:45 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-havayay4wure" 2025/03/14 06:22:45 DEBUG : Creating backend with remote "TestDrive:crypt/sma5oqt12gjb914qvfbk70ub29ghe2j83k4l0aqthk3qiudn983g" 2025/03/14 06:22:46 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-havayay4wure': Using server-side directory move 2025/03/14 06:22:46 INFO : Encrypted drive 'TestCryptDrive:rclone-test-havayay4wure': Server side directory move succeeded 2025/03/14 06:22:47 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-havayay4wure': Purge remote 2025/03/14 06:22:48 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-fobilac3cazu': Purge remote 2025/03/14 06:22:48 NOTICE: purge failed: directory not found --- PASS: TestServerSideMove (15.26s) === RUN TestServerSideMoveWithFilter run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-bebopij4liga'", Local "Local file system at /tmp/rclone492104059", Modify Window "1ms" 2025/03/14 06:22:48 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-kifaciw3puxe" 2025/03/14 06:22:48 DEBUG : Creating backend with remote "TestDrive:crypt/rui9k5k703j1ena69dts2dncrgoqdnekth1r4tq303alm98lle00" 2025/03/14 06:22:51 DEBUG : potato2: md5 = 5ace42b2aa935636299d45efbba41cd2 OK 2025/03/14 06:22:52 DEBUG : empty space: md5 = 4f884e9106592565d11f823c56d7fcfd OK 2025/03/14 06:22:53 DEBUG : potato3: md5 = e942def3e6b29d23fe09841f0874645d OK sync_test.go:1705: Server side move (if possible) Encrypted drive 'TestCryptDrive:rclone-test-bebopij4liga' -> Encrypted drive 'TestCryptDrive:rclone-test-kifaciw3puxe' 2025/03/14 06:22:56 DEBUG : empty space: md5 = 8f6c994607ed522b82c194b323678f71 OK 2025/03/14 06:22:57 DEBUG : potato3: md5 = d0a9d4347863f4923230aeea323bfa81 OK 2025/03/14 06:22:58 DEBUG : empty space: Excluded (Size Filter) 2025/03/14 06:22:58 DEBUG : empty space: Excluded 2025/03/14 06:22:58 DEBUG : empty space: Excluded (Size Filter) 2025/03/14 06:22:58 DEBUG : empty space: Excluded 2025/03/14 06:22:58 DEBUG : potato2: Need to transfer - File not found at Destination 2025/03/14 06:22:58 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-kifaciw3puxe': Waiting for checks to finish 2025/03/14 06:22:58 DEBUG : potato3: Sizes differ (src 68 vs dst 60) 2025/03/14 06:22:58 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-kifaciw3puxe': Waiting for transfers to finish 2025/03/14 06:22:58 INFO : potato3: Deleted 2025/03/14 06:22:58 INFO : potato2: Moved (server-side) 2025/03/14 06:22:59 INFO : potato3: Moved (server-side) 2025/03/14 06:22:59 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-cotitow3soqo" 2025/03/14 06:22:59 DEBUG : Creating backend with remote "TestDrive:crypt/lktjnuc52lefvgdfro8a7vrpf47f1qm3a45fk5rm61ol6gkqlksg" 2025/03/14 06:23:01 DEBUG : empty space: Excluded (Size Filter) 2025/03/14 06:23:01 DEBUG : empty space: Excluded 2025/03/14 06:23:01 DEBUG : potato2: Need to transfer - File not found at Destination 2025/03/14 06:23:01 DEBUG : potato3: Need to transfer - File not found at Destination 2025/03/14 06:23:01 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-cotitow3soqo': Waiting for checks to finish 2025/03/14 06:23:01 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-cotitow3soqo': Waiting for transfers to finish 2025/03/14 06:23:02 INFO : potato2: Moved (server-side) 2025/03/14 06:23:02 INFO : potato3: Moved (server-side) 2025/03/14 06:23:03 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-cotitow3soqo': Purge remote 2025/03/14 06:23:03 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-kifaciw3puxe': Purge remote --- PASS: TestServerSideMoveWithFilter (16.11s) === RUN TestServerSideMoveDeleteEmptySourceDirs run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-bebopij4liga'", Local "Local file system at /tmp/rclone492104059", Modify Window "1ms" 2025/03/14 06:23:05 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-cojusox4refa" 2025/03/14 06:23:05 DEBUG : Creating backend with remote "TestDrive:crypt/0hnqqm0sqnpataocas5kd8aags3gi6sq14ak4fe822tnvg53pk5g" 2025/03/14 06:23:07 DEBUG : potato2: md5 = 25a50e1c7d865b69ed0b414f064236b2 OK 2025/03/14 06:23:08 DEBUG : empty space: md5 = f4378977b085dbccef652cfeda5c1574 OK 2025/03/14 06:23:10 DEBUG : potato3: md5 = 70ebcfdca0a6d6b0263e37044d644963 OK 2025/03/14 06:23:10 INFO : tomatoDir: Making directory sync_test.go:1705: Server side move (if possible) Encrypted drive 'TestCryptDrive:rclone-test-bebopij4liga' -> Encrypted drive 'TestCryptDrive:rclone-test-cojusox4refa' 2025/03/14 06:23:13 DEBUG : empty space: md5 = a6f45dc6090a3a0f33c7574a2504eb90 OK 2025/03/14 06:23:14 DEBUG : potato3: md5 = bd8a4828f6c5140ccf707dc47b01715b OK 2025/03/14 06:23:15 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-cojusox4refa': Using server-side directory move 2025/03/14 06:23:15 INFO : Encrypted drive 'TestCryptDrive:rclone-test-cojusox4refa': Server side directory move failed - fallback to file moves: can't copy directory - destination already exists 2025/03/14 06:23:15 DEBUG : potato2: Need to transfer - File not found at Destination 2025/03/14 06:23:15 DEBUG : Added delayed dir = "tomatoDir", newDst= 2025/03/14 06:23:15 DEBUG : empty space: Size and modification time the same (differ by 0s, within tolerance 1ms) 2025/03/14 06:23:15 DEBUG : empty space: Unchanged skipping 2025/03/14 06:23:15 DEBUG : potato3: Sizes differ (src 68 vs dst 60) 2025/03/14 06:23:15 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-cojusox4refa': Waiting for checks to finish 2025/03/14 06:23:15 INFO : empty space: Deleted 2025/03/14 06:23:15 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-cojusox4refa': Waiting for transfers to finish 2025/03/14 06:23:15 INFO : potato3: Deleted 2025/03/14 06:23:15 INFO : potato2: Moved (server-side) 2025/03/14 06:23:16 INFO : potato3: Moved (server-side) 2025/03/14 06:23:16 INFO : tomatoDir: Removing directory 2025/03/14 06:23:17 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-bebopij4liga': deleted 1 directories 2025/03/14 06:23:17 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-pazikek1huru" 2025/03/14 06:23:17 DEBUG : Creating backend with remote "TestDrive:crypt/a447dfoio7atq5gqvqjle0m8q1atti3ikts3firr1nb8s5hq4j3g" 2025/03/14 06:23:18 INFO : tomatoDir: Making directory 2025/03/14 06:23:19 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pazikek1huru': Using server-side directory move 2025/03/14 06:23:20 INFO : Encrypted drive 'TestCryptDrive:rclone-test-pazikek1huru': Server side directory move succeeded 2025/03/14 06:23:21 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pazikek1huru': Purge remote 2025/03/14 06:23:22 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-cojusox4refa': Purge remote 2025/03/14 06:23:22 NOTICE: purge failed: directory not found --- PASS: TestServerSideMoveDeleteEmptySourceDirs (18.03s) === RUN TestServerSideMoveOverlap run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-bebopij4liga'", Local "Local file system at /tmp/rclone492104059", Modify Window "1ms" sync_test.go:1910: Skipping test as remote supports DirMove --- SKIP: TestServerSideMoveOverlap (0.46s) === RUN TestSyncOverlap run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-bebopij4liga'", Local "Local file system at /tmp/rclone492104059", Modify Window "1ms" 2025/03/14 06:23:23 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-bebopij4liga/rclone-sync-test" 2025/03/14 06:23:23 DEBUG : Creating backend with remote "TestDrive:crypt/qkf5a5egif24gge3mq1m89pdh9bhtg3f78co71af63vrvok79gm0/i7355aa0sb89uagn75vfjqr6s3e3e1h2et8in57abn1fe8qfego0" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-bebopij4liga'", Local "Local file system at /tmp/rclone492104059", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-bebopij4liga'", Local "Local file system at /tmp/rclone492104059", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-bebopij4liga'", Local "Local file system at /tmp/rclone492104059", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-bebopij4liga'", Local "Local file system at /tmp/rclone492104059", Modify Window "1ms" --- PASS: TestSyncOverlap (3.97s) === RUN TestSyncOverlapWithFilter run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-bebopij4liga'", Local "Local file system at /tmp/rclone492104059", Modify Window "1ms" 2025/03/14 06:23:27 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-bebopij4liga/rclone-sync-test" 2025/03/14 06:23:27 DEBUG : Creating backend with remote "TestDrive:crypt/qkf5a5egif24gge3mq1m89pdh9bhtg3f78co71af63vrvok79gm0/i7355aa0sb89uagn75vfjqr6s3e3e1h2et8in57abn1fe8qfego0" 2025/03/14 06:23:29 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-bebopij4liga/rclone-sync-test-include/layer2" 2025/03/14 06:23:29 DEBUG : Creating backend with remote "TestDrive:crypt/qkf5a5egif24gge3mq1m89pdh9bhtg3f78co71af63vrvok79gm0/khf2vlblvnbf9ftevqm0htmss73hj1j5a7q328e4ohrgs7e2loe0/n01jpl9202nn9ec1rb75h0f1c4" 2025/03/14 06:23:32 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-bebopij4liga/rclone-sync-test-ignore-file" 2025/03/14 06:23:32 DEBUG : Creating backend with remote "TestDrive:crypt/qkf5a5egif24gge3mq1m89pdh9bhtg3f78co71af63vrvok79gm0/kmf11jujl9uha3tjganvgpkn45bu778hb5vb5riug1c26b38k7sg" 2025/03/14 06:23:36 DEBUG : rclone-sync-test-ignore-file/.ignore: md5 = b5e4d216a7f3e1adc862cda36a044f11 OK 2025/03/14 06:23:37 DEBUG : rclone-sync-test-ignore-file: Excluded 2025/03/14 06:23:38 DEBUG : rclone-sync-test: Excluded 2025/03/14 06:23:38 DEBUG : Added delayed dir = "rclone-sync-test-include", newDst= 2025/03/14 06:23:38 DEBUG : rclone-sync-test-include/layer2: Excluded 2025/03/14 06:23:38 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-bebopij4liga/rclone-sync-test': Waiting for checks to finish 2025/03/14 06:23:38 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-bebopij4liga/rclone-sync-test': Waiting for transfers to finish 2025/03/14 06:23:38 DEBUG : Waiting for deletions to finish 2025/03/14 06:23:38 INFO : There was nothing to transfer 2025/03/14 06:23:39 DEBUG : rclone-sync-test-ignore-file: Excluded 2025/03/14 06:23:40 DEBUG : rclone-sync-test: Excluded 2025/03/14 06:23:40 DEBUG : rclone-sync-test-include/layer2: Excluded 2025/03/14 06:23:40 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-bebopij4liga': Waiting for checks to finish 2025/03/14 06:23:40 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-bebopij4liga': Waiting for transfers to finish 2025/03/14 06:23:40 DEBUG : Waiting for deletions to finish 2025/03/14 06:23:40 INFO : rclone-sync-test-include: Removing directory 2025/03/14 06:23:40 DEBUG : khf2vlblvnbf9ftevqm0htmss73hj1j5a7q328e4ohrgs7e2loe0: Rmdir: contains file: "n01jpl9202nn9ec1rb75h0f1c4" 2025/03/14 06:23:40 DEBUG : rclone-sync-test-include: Failed to Rmdir: directory not empty 2025/03/14 06:23:40 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-bebopij4liga': failed to delete 1 directories 2025/03/14 06:23:40 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-bebopij4liga'", Local "Local file system at /tmp/rclone492104059", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-bebopij4liga'", Local "Local file system at /tmp/rclone492104059", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-bebopij4liga'", Local "Local file system at /tmp/rclone492104059", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-bebopij4liga'", Local "Local file system at /tmp/rclone492104059", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-bebopij4liga'", Local "Local file system at /tmp/rclone492104059", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-bebopij4liga'", Local "Local file system at /tmp/rclone492104059", Modify Window "1ms" 2025/03/14 06:23:41 DEBUG : rclone-sync-test-ignore-file: Excluded 2025/03/14 06:23:42 DEBUG : rclone-sync-test: Excluded 2025/03/14 06:23:42 DEBUG : Added delayed dir = "rclone-sync-test-include", newDst= 2025/03/14 06:23:42 DEBUG : rclone-sync-test-include/layer2: Excluded 2025/03/14 06:23:42 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-bebopij4liga/rclone-sync-test-include/layer2': Waiting for checks to finish 2025/03/14 06:23:42 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-bebopij4liga/rclone-sync-test-include/layer2': Waiting for transfers to finish 2025/03/14 06:23:42 DEBUG : Waiting for deletions to finish 2025/03/14 06:23:42 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-bebopij4liga'", Local "Local file system at /tmp/rclone492104059", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-bebopij4liga'", Local "Local file system at /tmp/rclone492104059", Modify Window "1ms" 2025/03/14 06:23:43 DEBUG : rclone-sync-test-ignore-file: Excluded 2025/03/14 06:23:43 DEBUG : rclone-sync-test: Excluded 2025/03/14 06:23:44 DEBUG : rclone-sync-test-include/layer2: Excluded 2025/03/14 06:23:44 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-bebopij4liga': Waiting for checks to finish 2025/03/14 06:23:44 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-bebopij4liga': Waiting for transfers to finish 2025/03/14 06:23:44 DEBUG : Waiting for deletions to finish 2025/03/14 06:23:44 INFO : rclone-sync-test-include: Removing directory 2025/03/14 06:23:44 DEBUG : khf2vlblvnbf9ftevqm0htmss73hj1j5a7q328e4ohrgs7e2loe0: Rmdir: contains file: "n01jpl9202nn9ec1rb75h0f1c4" 2025/03/14 06:23:44 DEBUG : rclone-sync-test-include: Failed to Rmdir: directory not empty 2025/03/14 06:23:44 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-bebopij4liga': failed to delete 1 directories 2025/03/14 06:23:44 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-bebopij4liga'", Local "Local file system at /tmp/rclone492104059", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-bebopij4liga'", Local "Local file system at /tmp/rclone492104059", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-bebopij4liga'", Local "Local file system at /tmp/rclone492104059", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-bebopij4liga'", Local "Local file system at /tmp/rclone492104059", Modify Window "1ms" 2025/03/14 06:23:45 DEBUG : : Excluded 2025/03/14 06:23:45 DEBUG : rclone-sync-test-ignore-file: Excluded 2025/03/14 06:23:45 DEBUG : rclone-sync-test: Excluded 2025/03/14 06:23:45 DEBUG : Added delayed dir = "rclone-sync-test-include", newDst= 2025/03/14 06:23:46 DEBUG : rclone-sync-test-include/layer2: Excluded 2025/03/14 06:23:46 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-bebopij4liga/rclone-sync-test-ignore-file': Waiting for checks to finish 2025/03/14 06:23:46 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-bebopij4liga/rclone-sync-test-ignore-file': Waiting for transfers to finish 2025/03/14 06:23:46 DEBUG : Waiting for deletions to finish 2025/03/14 06:23:46 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-bebopij4liga'", Local "Local file system at /tmp/rclone492104059", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-bebopij4liga'", Local "Local file system at /tmp/rclone492104059", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-bebopij4liga'", Local "Local file system at /tmp/rclone492104059", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-bebopij4liga'", Local "Local file system at /tmp/rclone492104059", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-bebopij4liga'", Local "Local file system at /tmp/rclone492104059", Modify Window "1ms" 2025/03/14 06:23:48 DEBUG : khf2vlblvnbf9ftevqm0htmss73hj1j5a7q328e4ohrgs7e2loe0: Rmdir: contains trashed file: "n01jpl9202nn9ec1rb75h0f1c4" 2025/03/14 06:23:49 DEBUG : kmf11jujl9uha3tjganvgpkn45bu778hb5vb5riug1c26b38k7sg: Rmdir: contains trashed file: "i0t74httmdlljg425j6tg570d8" --- PASS: TestSyncOverlapWithFilter (30.98s) === RUN TestSyncCompareDest run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-bebopij4liga'", Local "Local file system at /tmp/rclone492104059", Modify Window "1ms" 2025/03/14 06:23:58 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-bebopij4liga/dst" 2025/03/14 06:23:58 DEBUG : Creating backend with remote "TestDrive:crypt/qkf5a5egif24gge3mq1m89pdh9bhtg3f78co71af63vrvok79gm0/31u3jie661vd5p8j7rtc3hgbh0" 2025/03/14 06:23:59 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-bebopij4liga/CompareDest" 2025/03/14 06:24:00 DEBUG : Creating backend with remote "TestDrive:crypt/qkf5a5egif24gge3mq1m89pdh9bhtg3f78co71af63vrvok79gm0/gveqi14airsml4bgu7krj116o8" 2025/03/14 06:24:02 DEBUG : one: Need to transfer - File not found at Destination 2025/03/14 06:24:02 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-bebopij4liga/dst': Waiting for checks to finish 2025/03/14 06:24:02 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-bebopij4liga/dst': Waiting for transfers to finish 2025/03/14 06:24:04 DEBUG : one: md5 = c156476eb1b975de9eb0a37e8f90bd72 OK 2025/03/14 06:24:04 INFO : one: Copied (new) 2025/03/14 06:24:04 DEBUG : Waiting for deletions to finish 2025/03/14 06:24:05 DEBUG : one: Sizes differ (src 5 vs dst 3) 2025/03/14 06:24:05 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-bebopij4liga/dst': Waiting for checks to finish 2025/03/14 06:24:05 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-bebopij4liga/dst': Waiting for transfers to finish 2025/03/14 06:24:06 DEBUG : one: md5 = 6c80fe545fb55a616333cf34d2c0889d OK 2025/03/14 06:24:06 INFO : one: Copied (replaced existing) 2025/03/14 06:24:06 DEBUG : Waiting for deletions to finish 2025/03/14 06:24:08 DEBUG : dst/one: md5 = 5e1dde7c6237cffee2eb2974702a2eb5 OK 2025/03/14 06:24:11 DEBUG : CompareDest/one: md5 = 4b42197741c248836e6a2977eaba5038 OK 2025/03/14 06:24:11 DEBUG : one: Sizes differ (src 5 vs dst 3) 2025/03/14 06:24:11 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-bebopij4liga/dst': Waiting for checks to finish 2025/03/14 06:24:12 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/03/14 06:24:12 DEBUG : one: Destination found in --compare-dest, skipping 2025/03/14 06:24:12 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-bebopij4liga/dst': Waiting for transfers to finish 2025/03/14 06:24:12 DEBUG : Waiting for deletions to finish 2025/03/14 06:24:12 INFO : There was nothing to transfer 2025/03/14 06:24:14 DEBUG : CompareDest/two: md5 = 93295b9944a7c15c6d4cb359a031252f OK 2025/03/14 06:24:15 DEBUG : two: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/03/14 06:24:15 DEBUG : two: Destination found in --compare-dest, skipping 2025/03/14 06:24:15 DEBUG : one: Sizes differ (src 5 vs dst 3) 2025/03/14 06:24:15 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-bebopij4liga/dst': Waiting for checks to finish 2025/03/14 06:24:15 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/03/14 06:24:15 DEBUG : one: Destination found in --compare-dest, skipping 2025/03/14 06:24:15 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-bebopij4liga/dst': Waiting for transfers to finish 2025/03/14 06:24:15 DEBUG : Waiting for deletions to finish 2025/03/14 06:24:15 INFO : There was nothing to transfer 2025/03/14 06:24:16 DEBUG : two: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/03/14 06:24:16 DEBUG : two: Destination found in --compare-dest, skipping 2025/03/14 06:24:16 DEBUG : one: Sizes differ (src 5 vs dst 3) 2025/03/14 06:24:16 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-bebopij4liga/dst': Waiting for checks to finish 2025/03/14 06:24:16 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/03/14 06:24:16 DEBUG : one: Destination found in --compare-dest, skipping 2025/03/14 06:24:16 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-bebopij4liga/dst': Waiting for transfers to finish 2025/03/14 06:24:16 DEBUG : Waiting for deletions to finish 2025/03/14 06:24:16 INFO : There was nothing to transfer sync_test.go:2175: No hash on uploaded file so skipping compare timestamp test 2025/03/14 06:24:18 DEBUG : two: Sizes differ (src 5 vs dst 3) 2025/03/14 06:24:18 DEBUG : two: Need to transfer - File not found at Destination 2025/03/14 06:24:18 DEBUG : one: Sizes differ (src 5 vs dst 3) 2025/03/14 06:24:18 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-bebopij4liga/dst': Waiting for checks to finish 2025/03/14 06:24:18 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/03/14 06:24:18 DEBUG : one: Destination found in --compare-dest, skipping 2025/03/14 06:24:18 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-bebopij4liga/dst': Waiting for transfers to finish 2025/03/14 06:24:19 DEBUG : two: md5 = 677f55209d7d40738b48ffe702bc819b OK 2025/03/14 06:24:19 INFO : two: Copied (new) 2025/03/14 06:24:19 DEBUG : Waiting for deletions to finish 2025/03/14 06:24:22 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k" 2025/03/14 06:24:22 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" 2025/03/14 06:24:23 DEBUG : gveqi14airsml4bgu7krj116o8: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k" 2025/03/14 06:24:23 DEBUG : gveqi14airsml4bgu7krj116o8: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" --- PASS: TestSyncCompareDest (25.76s) === RUN TestSyncMultipleCompareDest run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-bebopij4liga'", Local "Local file system at /tmp/rclone492104059", Modify Window "1ms" 2025/03/14 06:24:26 DEBUG : pre-dest1/1: md5 = 54c338f11647f9ca797ad88007cf1da6 OK 2025/03/14 06:24:28 DEBUG : pre-dest2/2: md5 = da5c3b12f8483b217d03019adb1eef35 OK 2025/03/14 06:24:29 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-bebopij4liga/dest" 2025/03/14 06:24:29 DEBUG : Creating backend with remote "TestDrive:crypt/qkf5a5egif24gge3mq1m89pdh9bhtg3f78co71af63vrvok79gm0/rg03c1jvnehrrc617i0lnqjddc" 2025/03/14 06:24:30 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-bebopij4liga/pre-dest1" 2025/03/14 06:24:30 DEBUG : Creating backend with remote "TestDrive:crypt/qkf5a5egif24gge3mq1m89pdh9bhtg3f78co71af63vrvok79gm0/bbnblvh6k061ssopqrp18kd7gc" 2025/03/14 06:24:31 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-bebopij4liga/pre-dest2" 2025/03/14 06:24:31 DEBUG : Creating backend with remote "TestDrive:crypt/qkf5a5egif24gge3mq1m89pdh9bhtg3f78co71af63vrvok79gm0/dgicm1h6b5ejvlltm8eeif0bnk" 2025/03/14 06:24:32 DEBUG : 1: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/03/14 06:24:32 DEBUG : 1: Destination found in --compare-dest, skipping 2025/03/14 06:24:33 DEBUG : 2: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/03/14 06:24:33 DEBUG : 2: Destination found in --compare-dest, skipping 2025/03/14 06:24:33 DEBUG : 3: Need to transfer - File not found at Destination 2025/03/14 06:24:33 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-bebopij4liga/dest': Waiting for checks to finish 2025/03/14 06:24:33 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-bebopij4liga/dest': Waiting for transfers to finish 2025/03/14 06:24:35 DEBUG : 3: md5 = c2e12d927935cc751c6fb0b48c2176a6 OK 2025/03/14 06:24:35 INFO : 3: Copied (new) 2025/03/14 06:24:35 DEBUG : Waiting for deletions to finish 2025/03/14 06:24:38 DEBUG : dgicm1h6b5ejvlltm8eeif0bnk: Rmdir: contains trashed file: "1ghu8geql9vrl726n32nrf65bc" 2025/03/14 06:24:39 DEBUG : bbnblvh6k061ssopqrp18kd7gc: Rmdir: contains trashed file: "skbfko3oil7es0lj68ob574sro" 2025/03/14 06:24:40 DEBUG : rg03c1jvnehrrc617i0lnqjddc: Rmdir: contains trashed file: "g072p7hmjchlnj0gibe64c1epg" --- PASS: TestSyncMultipleCompareDest (16.64s) === RUN TestSyncCopyDest run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-bebopij4liga'", Local "Local file system at /tmp/rclone492104059", Modify Window "1ms" 2025/03/14 06:24:40 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-bebopij4liga/dst" 2025/03/14 06:24:40 DEBUG : Creating backend with remote "TestDrive:crypt/qkf5a5egif24gge3mq1m89pdh9bhtg3f78co71af63vrvok79gm0/31u3jie661vd5p8j7rtc3hgbh0" 2025/03/14 06:24:42 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-bebopij4liga/CopyDest" 2025/03/14 06:24:42 DEBUG : Creating backend with remote "TestDrive:crypt/qkf5a5egif24gge3mq1m89pdh9bhtg3f78co71af63vrvok79gm0/d09o6po3f7bm6ce32vdgs8h9ls" 2025/03/14 06:24:44 DEBUG : one: Need to transfer - File not found at Destination 2025/03/14 06:24:44 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-bebopij4liga/dst': Waiting for checks to finish 2025/03/14 06:24:44 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-bebopij4liga/dst': Waiting for transfers to finish 2025/03/14 06:24:46 DEBUG : one: md5 = 760739ec1546f202aeea4fc6d133d71c OK 2025/03/14 06:24:46 INFO : one: Copied (new) 2025/03/14 06:24:46 DEBUG : Waiting for deletions to finish 2025/03/14 06:24:47 DEBUG : one: Sizes differ (src 5 vs dst 3) 2025/03/14 06:24:47 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-bebopij4liga/dst': Waiting for checks to finish 2025/03/14 06:24:48 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-bebopij4liga/dst': Waiting for transfers to finish 2025/03/14 06:24:49 DEBUG : one: md5 = a9adc8c8c45ca3798bc372813ce4995b OK 2025/03/14 06:24:49 INFO : one: Copied (replaced existing) 2025/03/14 06:24:49 DEBUG : Waiting for deletions to finish 2025/03/14 06:24:51 DEBUG : dst/one: md5 = de8b510a3d98f59ecec297980af34cf4 OK 2025/03/14 06:24:53 DEBUG : CopyDest/one: md5 = 0ea540e24ba3965db062f898f7de91e4 OK 2025/03/14 06:24:53 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-bebopij4liga/BackupDir" 2025/03/14 06:24:53 DEBUG : Creating backend with remote "TestDrive:crypt/qkf5a5egif24gge3mq1m89pdh9bhtg3f78co71af63vrvok79gm0/s6dbk3lfi7c9kfvo6j7bla9m0g" 2025/03/14 06:24:55 DEBUG : one: Sizes differ (src 5 vs dst 3) 2025/03/14 06:24:55 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-bebopij4liga/dst': Waiting for checks to finish 2025/03/14 06:24:56 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/03/14 06:24:56 DEBUG : one: Sizes differ (src 5 vs dst 3) 2025/03/14 06:24:57 INFO : one: Moved (server-side) 2025/03/14 06:24:59 INFO : one: Copied (server-side copy) 2025/03/14 06:24:59 DEBUG : one: Destination found in --copy-dest, using server-side copy 2025/03/14 06:24:59 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-bebopij4liga/dst': Waiting for transfers to finish 2025/03/14 06:24:59 DEBUG : Waiting for deletions to finish 2025/03/14 06:25:00 DEBUG : CopyDest/two: md5 = 675c6d20db5cdcecbabb21ba5eeb6422 OK 2025/03/14 06:25:01 DEBUG : two: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/03/14 06:25:02 INFO : two: Copied (server-side copy) 2025/03/14 06:25:02 DEBUG : two: Destination found in --copy-dest, using server-side copy 2025/03/14 06:25:02 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-bebopij4liga/dst': Waiting for checks to finish 2025/03/14 06:25:02 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/03/14 06:25:02 DEBUG : one: Unchanged skipping 2025/03/14 06:25:02 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-bebopij4liga/dst': Waiting for transfers to finish 2025/03/14 06:25:02 DEBUG : Waiting for deletions to finish 2025/03/14 06:25:03 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/03/14 06:25:03 DEBUG : one: Unchanged skipping 2025/03/14 06:25:03 DEBUG : two: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/03/14 06:25:03 DEBUG : two: Unchanged skipping 2025/03/14 06:25:03 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-bebopij4liga/dst': Waiting for checks to finish 2025/03/14 06:25:03 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-bebopij4liga/dst': Waiting for transfers to finish 2025/03/14 06:25:03 DEBUG : Waiting for deletions to finish 2025/03/14 06:25:03 INFO : There was nothing to transfer 2025/03/14 06:25:05 DEBUG : CopyDest/three: md5 = dcf5712e52823f46cb442dd7c1c1875b OK 2025/03/14 06:25:06 DEBUG : three: Sizes differ (src 7 vs dst 5) 2025/03/14 06:25:06 DEBUG : three: Destination not found in --copy-dest 2025/03/14 06:25:06 DEBUG : three: Need to transfer - File not found at Destination 2025/03/14 06:25:06 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/03/14 06:25:06 DEBUG : one: Unchanged skipping 2025/03/14 06:25:06 DEBUG : two: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/03/14 06:25:06 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-bebopij4liga/dst': Waiting for checks to finish 2025/03/14 06:25:06 DEBUG : two: Unchanged skipping 2025/03/14 06:25:06 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-bebopij4liga/dst': Waiting for transfers to finish 2025/03/14 06:25:07 DEBUG : three: md5 = 20db2e26baf1a8cbeaaba4101062fe89 OK 2025/03/14 06:25:07 INFO : three: Copied (new) 2025/03/14 06:25:07 DEBUG : Waiting for deletions to finish 2025/03/14 06:25:12 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "b6jdmn2b1adrhc8vikh7edr9os" 2025/03/14 06:25:12 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" 2025/03/14 06:25:12 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k" 2025/03/14 06:25:13 DEBUG : d09o6po3f7bm6ce32vdgs8h9ls: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" 2025/03/14 06:25:13 DEBUG : d09o6po3f7bm6ce32vdgs8h9ls: Rmdir: contains trashed file: "b6jdmn2b1adrhc8vikh7edr9os" 2025/03/14 06:25:13 DEBUG : d09o6po3f7bm6ce32vdgs8h9ls: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k" 2025/03/14 06:25:14 DEBUG : s6dbk3lfi7c9kfvo6j7bla9m0g: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" --- PASS: TestSyncCopyDest (34.18s) === RUN TestSyncBackupDir run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-bebopij4liga'", Local "Local file system at /tmp/rclone492104059", Modify Window "1ms" 2025/03/14 06:25:17 DEBUG : dst/one: md5 = 9ffc4101f444d5a5814e5a3c3f30dd41 OK 2025/03/14 06:25:18 DEBUG : dst/two: md5 = 89f33cc8442fb9320132fcefec8cf1f3 OK 2025/03/14 06:25:19 DEBUG : dst/three.txt: md5 = 936d6f7a44849e4594f5e709d9915df4 OK 2025/03/14 06:25:20 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-bebopij4liga/dst" 2025/03/14 06:25:20 DEBUG : Creating backend with remote "TestDrive:crypt/qkf5a5egif24gge3mq1m89pdh9bhtg3f78co71af63vrvok79gm0/31u3jie661vd5p8j7rtc3hgbh0" 2025/03/14 06:25:21 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-bebopij4liga/backup" 2025/03/14 06:25:21 DEBUG : Creating backend with remote "TestDrive:crypt/qkf5a5egif24gge3mq1m89pdh9bhtg3f78co71af63vrvok79gm0/1nrff024r7pq65ecp72fc28jb0" 2025/03/14 06:25:23 DEBUG : one: Sizes differ (src 4 vs dst 3) 2025/03/14 06:25:23 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/03/14 06:25:23 DEBUG : two: Unchanged skipping 2025/03/14 06:25:23 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-bebopij4liga/dst': Waiting for checks to finish 2025/03/14 06:25:24 INFO : one: Moved (server-side) 2025/03/14 06:25:24 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-bebopij4liga/dst': Waiting for transfers to finish 2025/03/14 06:25:26 DEBUG : one: md5 = e4ea25736bd6f3a22de975d2f51bbc06 OK 2025/03/14 06:25:26 INFO : one: Copied (new) 2025/03/14 06:25:26 DEBUG : Waiting for deletions to finish 2025/03/14 06:25:27 INFO : three.txt: Moved (server-side) 2025/03/14 06:25:27 INFO : three.txt: Moved into backup dir 2025/03/14 06:25:29 DEBUG : dst/three.txt: md5 = af692dec67febefa2e886b386d725466 OK 2025/03/14 06:25:29 DEBUG : one: Sizes differ (src 5 vs dst 4) 2025/03/14 06:25:29 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-bebopij4liga/dst': Waiting for checks to finish 2025/03/14 06:25:29 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/03/14 06:25:29 DEBUG : two: Unchanged skipping 2025/03/14 06:25:30 INFO : one: Deleted 2025/03/14 06:25:31 INFO : one: Moved (server-side) 2025/03/14 06:25:31 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-bebopij4liga/dst': Waiting for transfers to finish 2025/03/14 06:25:32 DEBUG : one: md5 = 1728ab448f8f1649ba0fe02b2ccd453e OK 2025/03/14 06:25:32 INFO : one: Copied (new) 2025/03/14 06:25:32 DEBUG : Waiting for deletions to finish 2025/03/14 06:25:33 INFO : three.txt: Deleted 2025/03/14 06:25:33 INFO : three.txt: Moved (server-side) 2025/03/14 06:25:33 INFO : three.txt: Moved into backup dir 2025/03/14 06:25:36 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" 2025/03/14 06:25:36 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k" 2025/03/14 06:25:37 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "tr2hj63d80ftlmvm6a952snjcc" 2025/03/14 06:25:37 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" 2025/03/14 06:25:37 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" 2025/03/14 06:25:37 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "tr2hj63d80ftlmvm6a952snjcc" --- PASS: TestSyncBackupDir (23.17s) === RUN TestSyncBackupDirWithSuffix run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-bebopij4liga'", Local "Local file system at /tmp/rclone492104059", Modify Window "1ms" 2025/03/14 06:25:40 DEBUG : dst/one: md5 = e758251ceced1a483acfc88cf5c960fe OK 2025/03/14 06:25:41 DEBUG : dst/two: md5 = 823dd4719a77b5e2c25b2a19924a0063 OK 2025/03/14 06:25:43 DEBUG : dst/three.txt: md5 = f1dc56c4e1efd8bd686fc98accbfc9bc OK 2025/03/14 06:25:43 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-bebopij4liga/dst" 2025/03/14 06:25:43 DEBUG : Creating backend with remote "TestDrive:crypt/qkf5a5egif24gge3mq1m89pdh9bhtg3f78co71af63vrvok79gm0/31u3jie661vd5p8j7rtc3hgbh0" 2025/03/14 06:25:44 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-bebopij4liga/backup" 2025/03/14 06:25:44 DEBUG : Creating backend with remote "TestDrive:crypt/qkf5a5egif24gge3mq1m89pdh9bhtg3f78co71af63vrvok79gm0/1nrff024r7pq65ecp72fc28jb0" 2025/03/14 06:25:46 DEBUG : one: Sizes differ (src 4 vs dst 3) 2025/03/14 06:25:46 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/03/14 06:25:46 DEBUG : two: Unchanged skipping 2025/03/14 06:25:46 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-bebopij4liga/dst': Waiting for checks to finish 2025/03/14 06:25:48 INFO : one: Moved (server-side) to: one.bak 2025/03/14 06:25:48 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-bebopij4liga/dst': Waiting for transfers to finish 2025/03/14 06:25:49 DEBUG : one: md5 = e186c4fce688d113a89b75c4e5b90418 OK 2025/03/14 06:25:49 INFO : one: Copied (new) 2025/03/14 06:25:49 DEBUG : Waiting for deletions to finish 2025/03/14 06:25:50 INFO : three.txt: Moved (server-side) to: three.txt.bak 2025/03/14 06:25:50 INFO : three.txt: Moved into backup dir 2025/03/14 06:25:52 DEBUG : dst/three.txt: md5 = f790727c85a8262dc73edf5dcaf1dcf6 OK 2025/03/14 06:25:52 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-bebopij4liga/dst': Waiting for checks to finish 2025/03/14 06:25:52 DEBUG : one: Sizes differ (src 5 vs dst 4) 2025/03/14 06:25:52 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/03/14 06:25:52 DEBUG : two: Unchanged skipping 2025/03/14 06:25:53 INFO : one.bak: Deleted 2025/03/14 06:25:54 INFO : one: Moved (server-side) to: one.bak 2025/03/14 06:25:54 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-bebopij4liga/dst': Waiting for transfers to finish 2025/03/14 06:25:55 DEBUG : one: md5 = c4dcd84dda7397ea0273bf361462b0a9 OK 2025/03/14 06:25:55 INFO : one: Copied (new) 2025/03/14 06:25:55 DEBUG : Waiting for deletions to finish 2025/03/14 06:25:56 INFO : three.txt.bak: Deleted 2025/03/14 06:25:57 INFO : three.txt: Moved (server-side) to: three.txt.bak 2025/03/14 06:25:57 INFO : three.txt: Moved into backup dir 2025/03/14 06:26:00 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" 2025/03/14 06:26:00 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k" 2025/03/14 06:26:01 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "sk91qgsqfn0r271r2ehsaoc20c" 2025/03/14 06:26:01 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "qltcak2uaegtmcoa8vijdppbp8" 2025/03/14 06:26:01 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "sk91qgsqfn0r271r2ehsaoc20c" 2025/03/14 06:26:01 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "qltcak2uaegtmcoa8vijdppbp8" --- PASS: TestSyncBackupDirWithSuffix (23.84s) === RUN TestSyncBackupDirWithSuffixKeepExtension run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-bebopij4liga'", Local "Local file system at /tmp/rclone492104059", Modify Window "1ms" 2025/03/14 06:26:04 DEBUG : dst/one: md5 = aabb67d230474f4cb36f558412ecc344 OK 2025/03/14 06:26:05 DEBUG : dst/two: md5 = dc76a03415a8378ec290e0b11bbf3eae OK 2025/03/14 06:26:06 DEBUG : dst/three.txt: md5 = 28f6696b8bdf109e2248fff30014ca7e OK 2025/03/14 06:26:07 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-bebopij4liga/dst" 2025/03/14 06:26:07 DEBUG : Creating backend with remote "TestDrive:crypt/qkf5a5egif24gge3mq1m89pdh9bhtg3f78co71af63vrvok79gm0/31u3jie661vd5p8j7rtc3hgbh0" 2025/03/14 06:26:08 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-bebopij4liga/backup" 2025/03/14 06:26:08 DEBUG : Creating backend with remote "TestDrive:crypt/qkf5a5egif24gge3mq1m89pdh9bhtg3f78co71af63vrvok79gm0/1nrff024r7pq65ecp72fc28jb0" 2025/03/14 06:26:09 DEBUG : one: Sizes differ (src 4 vs dst 3) 2025/03/14 06:26:09 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/03/14 06:26:09 DEBUG : two: Unchanged skipping 2025/03/14 06:26:09 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-bebopij4liga/dst': Waiting for checks to finish 2025/03/14 06:26:11 INFO : one: Moved (server-side) to: one-2019-01-01 2025/03/14 06:26:11 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-bebopij4liga/dst': Waiting for transfers to finish 2025/03/14 06:26:12 DEBUG : one: md5 = 5a659cf55fab2ccc9c1b754483ca221c OK 2025/03/14 06:26:12 INFO : one: Copied (new) 2025/03/14 06:26:12 DEBUG : Waiting for deletions to finish 2025/03/14 06:26:13 INFO : three.txt: Moved (server-side) to: three-2019-01-01.txt 2025/03/14 06:26:13 INFO : three.txt: Moved into backup dir 2025/03/14 06:26:15 DEBUG : dst/three.txt: md5 = 01fcc85476e226d3719744c6440f266f OK 2025/03/14 06:26:16 DEBUG : one: Sizes differ (src 5 vs dst 4) 2025/03/14 06:26:16 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/03/14 06:26:16 DEBUG : two: Unchanged skipping 2025/03/14 06:26:16 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-bebopij4liga/dst': Waiting for checks to finish 2025/03/14 06:26:17 INFO : one-2019-01-01: Deleted 2025/03/14 06:26:17 INFO : one: Moved (server-side) to: one-2019-01-01 2025/03/14 06:26:17 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-bebopij4liga/dst': Waiting for transfers to finish 2025/03/14 06:26:19 DEBUG : one: md5 = 29ad590c4d8219bff2b7e7db8d54dedc OK 2025/03/14 06:26:19 INFO : one: Copied (new) 2025/03/14 06:26:19 DEBUG : Waiting for deletions to finish 2025/03/14 06:26:19 INFO : three-2019-01-01.txt: Deleted 2025/03/14 06:26:20 INFO : three.txt: Moved (server-side) to: three-2019-01-01.txt 2025/03/14 06:26:20 INFO : three.txt: Moved into backup dir 2025/03/14 06:26:23 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" 2025/03/14 06:26:23 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k" 2025/03/14 06:26:24 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "qtq2f6qq4lgpsmj88vb7147qje3prudmtfdtr2342fth58vo9a50" 2025/03/14 06:26:24 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "jcjl1bv3ep0v8kt35lqql1co90" 2025/03/14 06:26:24 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "qtq2f6qq4lgpsmj88vb7147qje3prudmtfdtr2342fth58vo9a50" 2025/03/14 06:26:24 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "jcjl1bv3ep0v8kt35lqql1co90" --- PASS: TestSyncBackupDirWithSuffixKeepExtension (23.17s) === RUN TestSyncBackupDirSuffixOnly run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-bebopij4liga'", Local "Local file system at /tmp/rclone492104059", Modify Window "1ms" 2025/03/14 06:26:27 DEBUG : dst/one: md5 = b820c1291140edb5d54b2a65a06a8493 OK 2025/03/14 06:26:28 DEBUG : dst/two: md5 = af63ae7e4417df012a47f2b08e2971e4 OK 2025/03/14 06:26:30 DEBUG : dst/three.txt: md5 = e51cc66f143eec9484fce70f6f98a341 OK 2025/03/14 06:26:30 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-bebopij4liga/dst" 2025/03/14 06:26:30 DEBUG : Creating backend with remote "TestDrive:crypt/qkf5a5egif24gge3mq1m89pdh9bhtg3f78co71af63vrvok79gm0/31u3jie661vd5p8j7rtc3hgbh0" 2025/03/14 06:26:31 DEBUG : one: Sizes differ (src 4 vs dst 3) 2025/03/14 06:26:31 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-bebopij4liga/dst': Waiting for checks to finish 2025/03/14 06:26:31 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/03/14 06:26:31 DEBUG : two: Unchanged skipping 2025/03/14 06:26:32 INFO : one: Moved (server-side) to: one.bak 2025/03/14 06:26:32 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-bebopij4liga/dst': Waiting for transfers to finish 2025/03/14 06:26:33 DEBUG : one: md5 = ccba7d300bc288906676db0f382118f9 OK 2025/03/14 06:26:33 INFO : one: Copied (new) 2025/03/14 06:26:33 DEBUG : Waiting for deletions to finish 2025/03/14 06:26:34 INFO : three.txt: Moved (server-side) to: three.txt.bak 2025/03/14 06:26:34 INFO : three.txt: Moved into backup dir 2025/03/14 06:26:36 DEBUG : dst/three.txt: md5 = 0d3f014c6f6b9b809083b2d1d929f790 OK 2025/03/14 06:26:37 DEBUG : three.txt.bak: Excluded (Path Filter) 2025/03/14 06:26:37 DEBUG : three.txt.bak: Excluded 2025/03/14 06:26:37 DEBUG : one.bak: Excluded (Path Filter) 2025/03/14 06:26:37 DEBUG : one.bak: Excluded 2025/03/14 06:26:37 DEBUG : one: Sizes differ (src 5 vs dst 4) 2025/03/14 06:26:37 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/03/14 06:26:37 DEBUG : two: Unchanged skipping 2025/03/14 06:26:37 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-bebopij4liga/dst': Waiting for checks to finish 2025/03/14 06:26:37 INFO : one.bak: Deleted 2025/03/14 06:26:38 INFO : one: Moved (server-side) to: one.bak 2025/03/14 06:26:38 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-bebopij4liga/dst': Waiting for transfers to finish 2025/03/14 06:26:39 DEBUG : one: md5 = 4967e38c83385b3e0d0214c4a57e4360 OK 2025/03/14 06:26:39 INFO : one: Copied (new) 2025/03/14 06:26:39 DEBUG : Waiting for deletions to finish 2025/03/14 06:26:40 INFO : three.txt.bak: Deleted 2025/03/14 06:26:40 INFO : three.txt: Moved (server-side) to: three.txt.bak 2025/03/14 06:26:40 INFO : three.txt: Moved into backup dir 2025/03/14 06:26:43 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" 2025/03/14 06:26:43 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "sk91qgsqfn0r271r2ehsaoc20c" 2025/03/14 06:26:43 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "qltcak2uaegtmcoa8vijdppbp8" 2025/03/14 06:26:43 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "sk91qgsqfn0r271r2ehsaoc20c" 2025/03/14 06:26:43 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k" 2025/03/14 06:26:43 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "qltcak2uaegtmcoa8vijdppbp8" --- PASS: TestSyncBackupDirSuffixOnly (19.45s) === RUN TestSyncSuffix run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-bebopij4liga'", Local "Local file system at /tmp/rclone492104059", Modify Window "1ms" 2025/03/14 06:26:46 DEBUG : dst/one: md5 = f0fa07c847178842bf644636f1c9eef8 OK 2025/03/14 06:26:48 DEBUG : dst/two: md5 = 1b762ef002e4dbe237bdf8758a96d26f OK 2025/03/14 06:26:49 DEBUG : dst/three.txt: md5 = 14d39b6ecedf931c3c80b72b71fb3694 OK 2025/03/14 06:26:50 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-bebopij4liga/dst" 2025/03/14 06:26:50 DEBUG : Creating backend with remote "TestDrive:crypt/qkf5a5egif24gge3mq1m89pdh9bhtg3f78co71af63vrvok79gm0/31u3jie661vd5p8j7rtc3hgbh0" 2025/03/14 06:26:51 DEBUG : one: Sizes differ (src 4 vs dst 3) 2025/03/14 06:26:51 INFO : one: Moved (server-side) to: one.bak 2025/03/14 06:26:53 DEBUG : one: md5 = 02659a96bc1e53270cbaceb263e798dc OK 2025/03/14 06:26:53 INFO : one: Copied (new) 2025/03/14 06:26:53 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/03/14 06:26:53 DEBUG : two: Unchanged skipping 2025/03/14 06:26:53 DEBUG : three.txt: Sizes differ (src 6 vs dst 5) 2025/03/14 06:26:54 INFO : three.txt: Moved (server-side) to: three.txt.bak 2025/03/14 06:26:55 DEBUG : three.txt: md5 = 25bd4f592a3457fa89786010a6739051 OK 2025/03/14 06:26:55 INFO : three.txt: Copied (new) 2025/03/14 06:26:57 DEBUG : one: Sizes differ (src 5 vs dst 4) 2025/03/14 06:26:58 INFO : one.bak: Deleted 2025/03/14 06:26:58 INFO : one: Moved (server-side) to: one.bak 2025/03/14 06:26:59 DEBUG : one: md5 = 06e22bda73870e10be2d8e6226ecc427 OK 2025/03/14 06:26:59 INFO : one: Copied (new) 2025/03/14 06:27:00 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/03/14 06:27:00 DEBUG : two: Unchanged skipping 2025/03/14 06:27:00 DEBUG : three.txt: Sizes differ (src 19 vs dst 6) 2025/03/14 06:27:01 INFO : three.txt.bak: Deleted 2025/03/14 06:27:01 INFO : three.txt: Moved (server-side) to: three.txt.bak 2025/03/14 06:27:03 DEBUG : three.txt: md5 = f381e60c88c025f2ebe31902a5517580 OK 2025/03/14 06:27:03 INFO : three.txt: Copied (new) 2025/03/14 06:27:06 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "tr2hj63d80ftlmvm6a952snjcc" 2025/03/14 06:27:06 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" 2025/03/14 06:27:06 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "qltcak2uaegtmcoa8vijdppbp8" 2025/03/14 06:27:06 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "sk91qgsqfn0r271r2ehsaoc20c" 2025/03/14 06:27:06 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k" 2025/03/14 06:27:06 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "sk91qgsqfn0r271r2ehsaoc20c" 2025/03/14 06:27:06 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "qltcak2uaegtmcoa8vijdppbp8" --- PASS: TestSyncSuffix (22.89s) === RUN TestSyncSuffixKeepExtension run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-bebopij4liga'", Local "Local file system at /tmp/rclone492104059", Modify Window "1ms" 2025/03/14 06:27:09 DEBUG : dst/one: md5 = 0b995024c73016a1e4aa5c5d12f64d99 OK 2025/03/14 06:27:11 DEBUG : dst/two: md5 = 435e9b1628360860acb9321a84a10faf OK 2025/03/14 06:27:12 DEBUG : dst/three.txt: md5 = 563bb0ed4c70d331504dfd76196ae638 OK 2025/03/14 06:27:12 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-bebopij4liga/dst" 2025/03/14 06:27:12 DEBUG : Creating backend with remote "TestDrive:crypt/qkf5a5egif24gge3mq1m89pdh9bhtg3f78co71af63vrvok79gm0/31u3jie661vd5p8j7rtc3hgbh0" 2025/03/14 06:27:14 DEBUG : one: Sizes differ (src 4 vs dst 3) 2025/03/14 06:27:14 INFO : one: Moved (server-side) to: one-2019-01-01 2025/03/14 06:27:16 DEBUG : one: md5 = 49f0f056f8aa5dbb69df3d2d44cba4ed OK 2025/03/14 06:27:16 INFO : one: Copied (new) 2025/03/14 06:27:16 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/03/14 06:27:16 DEBUG : two: Unchanged skipping 2025/03/14 06:27:16 DEBUG : three.txt: Sizes differ (src 6 vs dst 5) 2025/03/14 06:27:17 INFO : three.txt: Moved (server-side) to: three-2019-01-01.txt 2025/03/14 06:27:19 DEBUG : three.txt: md5 = f43cf4915077abd5aa272d59a50599a1 OK 2025/03/14 06:27:19 INFO : three.txt: Copied (new) 2025/03/14 06:27:21 DEBUG : one: Sizes differ (src 5 vs dst 4) 2025/03/14 06:27:21 INFO : one-2019-01-01: Deleted 2025/03/14 06:27:22 INFO : one: Moved (server-side) to: one-2019-01-01 2025/03/14 06:27:23 DEBUG : one: md5 = 2ccd7bb6ec378b64096c0fb66ec862a9 OK 2025/03/14 06:27:23 INFO : one: Copied (new) 2025/03/14 06:27:23 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/03/14 06:27:23 DEBUG : two: Unchanged skipping 2025/03/14 06:27:24 DEBUG : three.txt: Sizes differ (src 19 vs dst 6) 2025/03/14 06:27:25 INFO : three-2019-01-01.txt: Deleted 2025/03/14 06:27:25 INFO : three.txt: Moved (server-side) to: three-2019-01-01.txt 2025/03/14 06:27:26 DEBUG : three.txt: md5 = a31c4677d8f716031ada708a874be9e2 OK 2025/03/14 06:27:26 INFO : three.txt: Copied (new) 2025/03/14 06:27:30 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "tr2hj63d80ftlmvm6a952snjcc" 2025/03/14 06:27:30 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" 2025/03/14 06:27:30 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "jcjl1bv3ep0v8kt35lqql1co90" 2025/03/14 06:27:30 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "qtq2f6qq4lgpsmj88vb7147qje3prudmtfdtr2342fth58vo9a50" 2025/03/14 06:27:30 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "jcjl1bv3ep0v8kt35lqql1co90" 2025/03/14 06:27:30 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k" 2025/03/14 06:27:30 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "qtq2f6qq4lgpsmj88vb7147qje3prudmtfdtr2342fth58vo9a50" --- PASS: TestSyncSuffixKeepExtension (23.82s) === RUN TestSyncUTFNorm run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-bebopij4liga'", Local "Local file system at /tmp/rclone492104059", Modify Window "1ms" 2025/03/14 06:27:32 DEBUG : Testêé: md5 = c2b7bb704cf00a7c8debaa33fc39fbc1 OK 2025/03/14 06:27:33 DEBUG : Testêé: Sizes differ (src 14 vs dst 18) 2025/03/14 06:27:33 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-bebopij4liga': Waiting for checks to finish 2025/03/14 06:27:33 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-bebopij4liga': Waiting for transfers to finish 2025/03/14 06:27:34 DEBUG : Testêé: md5 = 3bce306ad199aa979a4daaf568f32bea OK 2025/03/14 06:27:34 INFO : Testêé: Copied (replaced existing) to: Testêé 2025/03/14 06:27:34 DEBUG : Waiting for deletions to finish --- PASS: TestSyncUTFNorm (4.45s) === RUN TestSyncImmutable run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-bebopij4liga'", Local "Local file system at /tmp/rclone492104059", Modify Window "1ms" 2025/03/14 06:27:36 DEBUG : existing: Need to transfer - File not found at Destination 2025/03/14 06:27:36 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-bebopij4liga': Waiting for checks to finish 2025/03/14 06:27:36 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-bebopij4liga': Waiting for transfers to finish 2025/03/14 06:27:37 DEBUG : existing: md5 = 5e3fccaf9cce55042e85c4c6f7d0afd6 OK 2025/03/14 06:27:37 INFO : existing: Copied (new) 2025/03/14 06:27:37 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-bebopij4liga'", Local "Local file system at /tmp/rclone492104059", Modify Window "1ms" 2025/03/14 06:27:38 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-bebopij4liga': Waiting for checks to finish 2025/03/14 06:27:38 DEBUG : existing: Sizes differ (src 8 vs dst 6) 2025/03/14 06:27:38 ERROR : existing: Source and destination exist but do not match: immutable file modified 2025/03/14 06:27:38 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-bebopij4liga': Waiting for transfers to finish 2025/03/14 06:27:38 ERROR : Encrypted drive 'TestCryptDrive:rclone-test-bebopij4liga': not deleting files as there were IO errors 2025/03/14 06:27:38 ERROR : Encrypted drive 'TestCryptDrive:rclone-test-bebopij4liga': not deleting directories as there were IO errors run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-bebopij4liga'", Local "Local file system at /tmp/rclone492104059", Modify Window "1ms" --- PASS: TestSyncImmutable (4.99s) === RUN TestSyncIgnoreCase run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-bebopij4liga'", Local "Local file system at /tmp/rclone492104059", Modify Window "1ms" 2025/03/14 06:27:42 DEBUG : EXISTING: md5 = bab4dcb25e799db0a60ac5b629c9a713 OK 2025/03/14 06:27:42 DEBUG : existing: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/03/14 06:27:42 DEBUG : existing: Unchanged skipping 2025/03/14 06:27:42 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-bebopij4liga': Waiting for checks to finish 2025/03/14 06:27:42 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-bebopij4liga': Waiting for transfers to finish 2025/03/14 06:27:42 DEBUG : Waiting for deletions to finish 2025/03/14 06:27:42 INFO : There was nothing to transfer --- PASS: TestSyncIgnoreCase (3.09s) === RUN TestFixCase run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-bebopij4liga'", Local "Local file system at /tmp/rclone492104059", Modify Window "1ms" sync_test.go:2635: Skipping test as local or remote are case-sensitive --- SKIP: TestFixCase (0.46s) === RUN TestMaxTransfer === RUN TestMaxTransfer/Hard run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-bebopij4liga'", Local "Local file system at /tmp/rclone492104059", 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-bebopij4liga'", Local "Local file system at /tmp/rclone492104059", 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-bebopij4liga'", Local "Local file system at /tmp/rclone492104059", Modify Window "1ms" sync_test.go:2674: This test only runs on local --- PASS: TestMaxTransfer (1.42s) --- SKIP: TestMaxTransfer/Hard (0.44s) --- SKIP: TestMaxTransfer/Soft (0.49s) --- SKIP: TestMaxTransfer/Cautious (0.49s) === RUN TestSyncConcurrentDelete run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-bebopij4liga'", Local "Local file system at /tmp/rclone492104059", Modify Window "1ms" 2025/03/14 06:27:47 DEBUG : both0: md5 = 95be4d0feb0b647867f31fa572a54b9c OK 2025/03/14 06:27:48 DEBUG : only0: md5 = bee5837a851f6e898022e454e538f89e OK 2025/03/14 06:27:49 DEBUG : both1: md5 = a3a069701da5a39fb9761a310a0989e9 OK 2025/03/14 06:27:50 DEBUG : only1: md5 = 4e69ae5664b4c465fff79d16a22137a0 OK 2025/03/14 06:27:52 DEBUG : both2: md5 = b0a458fad2b704677c460d62485862b5 OK 2025/03/14 06:27:53 DEBUG : only2: md5 = 5645dffe368efa448dc36418d2c7da1e OK 2025/03/14 06:27:55 DEBUG : both3: md5 = f20e8eec89219d3d34a154a4a9069b08 OK 2025/03/14 06:27:56 DEBUG : only3: md5 = 261ee2533c8764dccad5f5756cc383d7 OK 2025/03/14 06:27:58 DEBUG : both4: md5 = a01164b8b5db6757283f9fe52c39e28c OK 2025/03/14 06:27:59 DEBUG : only4: md5 = 0b4d5914f70ddaff23dcebe5923effb3 OK 2025/03/14 06:28:00 DEBUG : both5: md5 = 4f60cdf58488cc23497b1c24a5841e9f OK 2025/03/14 06:28:02 DEBUG : only5: md5 = b6b88fdf4c3fed42e0a956d4fd0d589d OK 2025/03/14 06:28:03 DEBUG : both6: md5 = eaf5f66c6284de0303e954637a35cfb9 OK 2025/03/14 06:28:04 DEBUG : only6: md5 = 93db8a3e4a8cb2deb9ac7c241ebe6f6f OK 2025/03/14 06:28:06 DEBUG : both7: md5 = 343fa768b73fe66582c4b8645493e65c OK 2025/03/14 06:28:07 DEBUG : only7: md5 = a051fe336516d31fbd3a18886ab7fb35 OK 2025/03/14 06:28:09 DEBUG : both8: md5 = f2bc43b7d44c012b69458851f7b7ef51 OK 2025/03/14 06:28:10 DEBUG : only8: md5 = 4a23b6ea69c238356932f536989c1985 OK 2025/03/14 06:28:11 DEBUG : both9: md5 = e72e19b6ad53d298d1c9e2822bdf69d2 OK 2025/03/14 06:28:13 DEBUG : only9: md5 = dd8076d046d1355551e4400a2fe00d05 OK 2025/03/14 06:28:14 DEBUG : both10: md5 = 984fc14a897732b99a76a3f584ccf9d2 OK 2025/03/14 06:28:15 DEBUG : only10: md5 = df99d1a3e5840200fbde119abdf584d1 OK 2025/03/14 06:28:17 DEBUG : both11: md5 = 4c4116de210470b290214faf98f36f98 OK 2025/03/14 06:28:18 DEBUG : only11: md5 = b71d33753ffb89284e799a6649095051 OK 2025/03/14 06:28:20 DEBUG : both12: md5 = c29e7e446b1e51b9c6404267ed241837 OK 2025/03/14 06:28:21 DEBUG : only12: md5 = 924a2872552fd60c8c5c36d8cfc2bff2 OK 2025/03/14 06:28:22 DEBUG : both13: md5 = 5bcbd50c8fbd86ad58c92f202cdf4156 OK 2025/03/14 06:28:24 DEBUG : only13: md5 = 896979a090025530285aedf187907e57 OK 2025/03/14 06:28:25 DEBUG : both14: md5 = e2f74f049fda1e30b439f326f6ca9294 OK 2025/03/14 06:28:26 DEBUG : only14: md5 = 9bad4c29b349fc13a6ef5b6112d45a9b OK 2025/03/14 06:28:28 DEBUG : both15: md5 = 6358518b8db07bad103f1506f83ce138 OK 2025/03/14 06:28:29 DEBUG : only15: md5 = 93a1b2f1997a917c030c60b1aab74563 OK 2025/03/14 06:28:31 DEBUG : both16: md5 = 364ee3c8c454cd5024ad2f4ba93aaecd OK 2025/03/14 06:28:32 DEBUG : only16: md5 = 65438b3fcdac2523046e7a8678f6ada9 OK 2025/03/14 06:28:33 DEBUG : both17: md5 = 515a884b24e1d76f5e8e2b9c4672a264 OK 2025/03/14 06:28:35 DEBUG : only17: md5 = 344d1d3caf8d6d018a5fd20e5e326c9a OK 2025/03/14 06:28:36 DEBUG : both18: md5 = db9d57cf9f715a4d3db4463bbe0c21e7 OK 2025/03/14 06:28:38 DEBUG : only18: md5 = f955713a17c70c34e3d0550ee9a08fae OK 2025/03/14 06:28:39 DEBUG : both19: md5 = 2b63644270be9cd71e8085c75e9b7a79 OK 2025/03/14 06:28:40 DEBUG : only19: md5 = d42df97ebdb79426ce5e545aca35ea6c OK 2025/03/14 06:28:41 DEBUG : both0: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/03/14 06:28:41 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-bebopij4liga': Waiting for checks to finish 2025/03/14 06:28:41 DEBUG : both1: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/03/14 06:28:41 DEBUG : both10: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/03/14 06:28:41 DEBUG : both11: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/03/14 06:28:41 DEBUG : both0: Unchanged skipping 2025/03/14 06:28:41 DEBUG : both12: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/03/14 06:28:41 DEBUG : both12: Unchanged skipping 2025/03/14 06:28:41 DEBUG : both13: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/03/14 06:28:41 DEBUG : both1: Unchanged skipping 2025/03/14 06:28:41 DEBUG : both14: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/03/14 06:28:41 DEBUG : both14: Unchanged skipping 2025/03/14 06:28:41 DEBUG : both15: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/03/14 06:28:41 DEBUG : both15: Unchanged skipping 2025/03/14 06:28:41 DEBUG : both16: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/03/14 06:28:41 DEBUG : both16: Unchanged skipping 2025/03/14 06:28:41 DEBUG : both17: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/03/14 06:28:41 DEBUG : both17: Unchanged skipping 2025/03/14 06:28:41 DEBUG : both18: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/03/14 06:28:41 DEBUG : both10: Unchanged skipping 2025/03/14 06:28:41 DEBUG : both19: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/03/14 06:28:41 DEBUG : both19: Unchanged skipping 2025/03/14 06:28:41 DEBUG : both2: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/03/14 06:28:41 DEBUG : both11: Unchanged skipping 2025/03/14 06:28:41 DEBUG : both3: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/03/14 06:28:41 DEBUG : both13: Unchanged skipping 2025/03/14 06:28:41 DEBUG : both4: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/03/14 06:28:41 DEBUG : both18: Unchanged skipping 2025/03/14 06:28:41 DEBUG : both5: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/03/14 06:28:41 DEBUG : both5: Unchanged skipping 2025/03/14 06:28:41 DEBUG : both6: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/03/14 06:28:41 DEBUG : both2: Unchanged skipping 2025/03/14 06:28:41 DEBUG : both7: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/03/14 06:28:41 DEBUG : both7: Unchanged skipping 2025/03/14 06:28:41 DEBUG : both8: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/03/14 06:28:41 DEBUG : both8: Unchanged skipping 2025/03/14 06:28:41 DEBUG : both9: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/03/14 06:28:41 DEBUG : both9: Unchanged skipping 2025/03/14 06:28:41 DEBUG : both3: Unchanged skipping 2025/03/14 06:28:41 DEBUG : both4: Unchanged skipping 2025/03/14 06:28:41 DEBUG : both6: Unchanged skipping 2025/03/14 06:28:41 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-bebopij4liga': Waiting for transfers to finish 2025/03/14 06:28:41 DEBUG : Waiting for deletions to finish 2025/03/14 06:28:42 INFO : only11: Deleted 2025/03/14 06:28:42 INFO : only3: Deleted 2025/03/14 06:28:42 INFO : only17: Deleted 2025/03/14 06:28:42 INFO : only15: Deleted 2025/03/14 06:28:42 INFO : only4: Deleted 2025/03/14 06:28:42 INFO : only10: Deleted 2025/03/14 06:28:42 INFO : only0: Deleted 2025/03/14 06:28:42 INFO : only5: Deleted 2025/03/14 06:28:42 INFO : only7: Deleted 2025/03/14 06:28:42 INFO : only14: Deleted 2025/03/14 06:28:42 INFO : only8: Deleted 2025/03/14 06:28:42 INFO : only13: Deleted 2025/03/14 06:28:43 INFO : only16: Deleted 2025/03/14 06:28:43 INFO : only18: Deleted 2025/03/14 06:28:43 INFO : only2: Deleted 2025/03/14 06:28:43 INFO : only1: Deleted 2025/03/14 06:28:43 INFO : only12: Deleted 2025/03/14 06:28:43 INFO : only9: Deleted 2025/03/14 06:28:43 INFO : only19: Deleted 2025/03/14 06:28:43 INFO : only6: Deleted 2025/03/14 06:28:43 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-bebopij4liga'", Local "Local file system at /tmp/rclone492104059", Modify Window "1ms" --- PASS: TestSyncConcurrentDelete (68.61s) === RUN TestSyncConcurrentTruncate run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-bebopij4liga'", Local "Local file system at /tmp/rclone492104059", Modify Window "1ms" 2025/03/14 06:28:55 DEBUG : both0: md5 = 6376e7c46cd91dbad78bdf042533312f OK 2025/03/14 06:28:57 DEBUG : only0: md5 = fe66dcad001e744fa7e2f73bf4e4e6dd OK 2025/03/14 06:28:58 DEBUG : both1: md5 = 923bfc776656a4ead162f3a69f22184e OK 2025/03/14 06:28:59 DEBUG : only1: md5 = 3d6cc6f01b898729b62a34f2e0dc17f8 OK 2025/03/14 06:29:01 DEBUG : both2: md5 = 53426233efcd246964f9cf07e3a30e86 OK 2025/03/14 06:29:02 DEBUG : only2: md5 = c280a4cbc81c3b0c9399b96855ab0719 OK 2025/03/14 06:29:03 DEBUG : both3: md5 = d0ce506c4702c6a37ff903748a406632 OK 2025/03/14 06:29:05 DEBUG : only3: md5 = 020e76418c121132d93f12d94c8b0a81 OK 2025/03/14 06:29:06 DEBUG : both4: md5 = d36fdb45ce95a6ecbcecbaa1a865c03e OK 2025/03/14 06:29:08 DEBUG : only4: md5 = 082a4db3d8841ba8e6c23ae97d3b8528 OK 2025/03/14 06:29:09 DEBUG : both5: md5 = c6b9a3f16507a50baa6adcdc60fb661e OK 2025/03/14 06:29:10 DEBUG : only5: md5 = 1eb8be57c4600970691e0bfbc9deb411 OK 2025/03/14 06:29:12 DEBUG : both6: md5 = 1e9ad9c9e0350bca99737c5c9a171013 OK 2025/03/14 06:29:13 DEBUG : only6: md5 = 9b0f32e62fb20a25373cb9c07fcb136f OK 2025/03/14 06:29:15 DEBUG : both7: md5 = 08d076312df543e7ef768b46bb220a15 OK 2025/03/14 06:29:16 DEBUG : only7: md5 = 4dfa012744f9a3ffd2bec8b8e91b1e20 OK 2025/03/14 06:29:17 DEBUG : both8: md5 = 93b9101337844d7c771f9d998a345228 OK 2025/03/14 06:29:19 DEBUG : only8: md5 = ff2d8f5e6857cbc16d40c17607104593 OK 2025/03/14 06:29:20 DEBUG : both9: md5 = fcf560f722a2ca70b981d535cac0ea6c OK 2025/03/14 06:29:22 DEBUG : only9: md5 = 401e747109a03866d87b4fd0bafef6ff OK 2025/03/14 06:29:23 DEBUG : both10: md5 = 323bc4879cb533e2d792c702b7ca8a00 OK 2025/03/14 06:29:24 DEBUG : only10: md5 = 34b1c2328dcaab83d44ba6c9f986bc7d OK 2025/03/14 06:29:25 DEBUG : both11: md5 = fe23dea1e7d6a4018edd39f082817e9d OK 2025/03/14 06:29:27 DEBUG : only11: md5 = 99ee909abd47f6d0bb090aa95fea8a42 OK 2025/03/14 06:29:28 DEBUG : both12: md5 = 95fb8ee6856a4439adf342a815ac9831 OK 2025/03/14 06:29:30 DEBUG : only12: md5 = 9f5af740ca9765f6724676bc2da42c1d OK 2025/03/14 06:29:31 DEBUG : both13: md5 = 3b373b13ba0d07826f54cca9a8e05b3d OK 2025/03/14 06:29:32 DEBUG : only13: md5 = 0a0c9738f7a356d127e61ca6e48e9174 OK 2025/03/14 06:29:34 DEBUG : both14: md5 = 0ab718969df59d6b139f8effda66f896 OK 2025/03/14 06:29:35 DEBUG : only14: md5 = ad8fada1ae9322c7fec741e4c8d0e6a0 OK 2025/03/14 06:29:36 DEBUG : both15: md5 = 79c7afe86c79a92a0531129fc8b8b3f1 OK 2025/03/14 06:29:38 DEBUG : only15: md5 = 9b0ca404420e7a3cc6912e60a6ea3614 OK 2025/03/14 06:29:39 DEBUG : both16: md5 = 1a875b2724baa78c2473c7d3fdb17938 OK 2025/03/14 06:29:40 DEBUG : only16: md5 = f2cc4cc00034f79b4f9d403198adf036 OK 2025/03/14 06:29:42 DEBUG : both17: md5 = 2f0d452c4653504a61c343418b60c063 OK 2025/03/14 06:29:43 DEBUG : only17: md5 = 71f7e271af1994f2906556eca0a8e8e2 OK 2025/03/14 06:29:44 DEBUG : both18: md5 = 3ef41d4ade97398bceed26359880a233 OK 2025/03/14 06:29:46 DEBUG : only18: md5 = 745a433debba8074574e629a4d0c107d OK 2025/03/14 06:29:47 DEBUG : both19: md5 = c51993cab673c15d6994286b5fc12c4b OK 2025/03/14 06:29:49 DEBUG : only19: md5 = 3278b2aae24d6e6a112752cbb80df93d OK 2025/03/14 06:29:49 DEBUG : both0: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/03/14 06:29:49 DEBUG : both1: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/03/14 06:29:49 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-bebopij4liga': Waiting for checks to finish 2025/03/14 06:29:49 DEBUG : both11: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/03/14 06:29:49 DEBUG : both10: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/03/14 06:29:49 DEBUG : both0: Unchanged skipping 2025/03/14 06:29:49 DEBUG : both12: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/03/14 06:29:49 DEBUG : both12: Unchanged skipping 2025/03/14 06:29:49 DEBUG : both13: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/03/14 06:29:49 DEBUG : both1: Unchanged skipping 2025/03/14 06:29:49 DEBUG : both14: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/03/14 06:29:49 DEBUG : both14: Unchanged skipping 2025/03/14 06:29:49 DEBUG : both15: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/03/14 06:29:49 DEBUG : both15: Unchanged skipping 2025/03/14 06:29:49 DEBUG : both16: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/03/14 06:29:49 DEBUG : both16: Unchanged skipping 2025/03/14 06:29:49 DEBUG : both17: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/03/14 06:29:49 DEBUG : both17: Unchanged skipping 2025/03/14 06:29:49 DEBUG : both18: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/03/14 06:29:49 DEBUG : both18: Unchanged skipping 2025/03/14 06:29:49 DEBUG : both19: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/03/14 06:29:49 DEBUG : both19: Unchanged skipping 2025/03/14 06:29:49 DEBUG : both2: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/03/14 06:29:49 DEBUG : both2: Unchanged skipping 2025/03/14 06:29:49 DEBUG : both3: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/03/14 06:29:49 DEBUG : both3: Unchanged skipping 2025/03/14 06:29:49 DEBUG : both4: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/03/14 06:29:49 DEBUG : both4: Unchanged skipping 2025/03/14 06:29:49 DEBUG : both5: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/03/14 06:29:49 DEBUG : both5: Unchanged skipping 2025/03/14 06:29:49 DEBUG : both6: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/03/14 06:29:49 DEBUG : both6: Unchanged skipping 2025/03/14 06:29:49 DEBUG : both7: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/03/14 06:29:49 DEBUG : both7: Unchanged skipping 2025/03/14 06:29:49 DEBUG : both8: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/03/14 06:29:49 DEBUG : both8: Unchanged skipping 2025/03/14 06:29:49 DEBUG : both9: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/03/14 06:29:49 DEBUG : both9: Unchanged skipping 2025/03/14 06:29:49 DEBUG : only0: Sizes differ (src 0 vs dst 6) 2025/03/14 06:29:49 DEBUG : only1: Sizes differ (src 0 vs dst 6) 2025/03/14 06:29:49 DEBUG : only10: Sizes differ (src 0 vs dst 6) 2025/03/14 06:29:49 DEBUG : only11: Sizes differ (src 0 vs dst 6) 2025/03/14 06:29:49 DEBUG : only12: Sizes differ (src 0 vs dst 6) 2025/03/14 06:29:49 DEBUG : only13: Sizes differ (src 0 vs dst 6) 2025/03/14 06:29:49 DEBUG : only14: Sizes differ (src 0 vs dst 6) 2025/03/14 06:29:49 DEBUG : only15: Sizes differ (src 0 vs dst 6) 2025/03/14 06:29:49 DEBUG : only16: Sizes differ (src 0 vs dst 6) 2025/03/14 06:29:49 DEBUG : only17: Sizes differ (src 0 vs dst 6) 2025/03/14 06:29:49 DEBUG : only18: Sizes differ (src 0 vs dst 6) 2025/03/14 06:29:49 DEBUG : only19: Sizes differ (src 0 vs dst 6) 2025/03/14 06:29:49 DEBUG : only2: Sizes differ (src 0 vs dst 6) 2025/03/14 06:29:49 DEBUG : only3: Sizes differ (src 0 vs dst 6) 2025/03/14 06:29:49 DEBUG : only4: Sizes differ (src 0 vs dst 6) 2025/03/14 06:29:49 DEBUG : only5: Sizes differ (src 0 vs dst 6) 2025/03/14 06:29:49 DEBUG : only6: Sizes differ (src 0 vs dst 6) 2025/03/14 06:29:49 DEBUG : only7: Sizes differ (src 0 vs dst 6) 2025/03/14 06:29:49 DEBUG : only8: Sizes differ (src 0 vs dst 6) 2025/03/14 06:29:49 DEBUG : only9: Sizes differ (src 0 vs dst 6) 2025/03/14 06:29:49 DEBUG : both11: Unchanged skipping 2025/03/14 06:29:49 DEBUG : both10: Unchanged skipping 2025/03/14 06:29:49 DEBUG : both13: Unchanged skipping 2025/03/14 06:29:49 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-bebopij4liga': Waiting for transfers to finish 2025/03/14 06:29:50 DEBUG : only11: md5 = fbb4d6217291db8e93899796ce558e94 OK 2025/03/14 06:29:50 INFO : only11: Copied (replaced existing) 2025/03/14 06:29:50 DEBUG : only10: md5 = 4577330b34e188d233b24e8d17cda6ef OK 2025/03/14 06:29:50 INFO : only10: Copied (replaced existing) 2025/03/14 06:29:50 DEBUG : only1: md5 = c847617e36ccf1a22c712981af043cd9 OK 2025/03/14 06:29:50 INFO : only1: Copied (replaced existing) 2025/03/14 06:29:50 DEBUG : only0: md5 = bbfcc0eb5b59477ad2fcd458db85c756 OK 2025/03/14 06:29:50 INFO : only0: Copied (replaced existing) 2025/03/14 06:29:51 DEBUG : only12: md5 = cfc067db1988fc1e6e106597a64f1a20 OK 2025/03/14 06:29:51 INFO : only12: Copied (replaced existing) 2025/03/14 06:29:51 DEBUG : only13: md5 = ba954b89ececf715f944ac18b5802630 OK 2025/03/14 06:29:51 INFO : only13: Copied (replaced existing) 2025/03/14 06:29:52 DEBUG : only14: md5 = 859e54e6784a262685dceb058005a14b OK 2025/03/14 06:29:52 INFO : only14: Copied (replaced existing) 2025/03/14 06:29:52 DEBUG : only15: md5 = da5b483cb8362af7174062a70abbdbe0 OK 2025/03/14 06:29:52 INFO : only15: Copied (replaced existing) 2025/03/14 06:29:53 DEBUG : only16: md5 = ea3e722f00be08eb71e0fa065d2a1b70 OK 2025/03/14 06:29:53 INFO : only16: Copied (replaced existing) 2025/03/14 06:29:53 DEBUG : only17: md5 = 1921678ddbb1fe07183b77e9194e6df4 OK 2025/03/14 06:29:53 INFO : only17: Copied (replaced existing) 2025/03/14 06:29:53 DEBUG : only18: md5 = d9de8a7b41913ff6eebc283813b83cc2 OK 2025/03/14 06:29:53 INFO : only18: Copied (replaced existing) 2025/03/14 06:29:53 DEBUG : only19: md5 = c51f3cf62e98ec177de6a0a0f867568d OK 2025/03/14 06:29:53 INFO : only19: Copied (replaced existing) 2025/03/14 06:29:54 DEBUG : only3: md5 = 4240fe917dfaab93173db2211c442327 OK 2025/03/14 06:29:54 INFO : only3: Copied (replaced existing) 2025/03/14 06:29:54 DEBUG : only2: md5 = 0ca9c05b3f6e0b623f14e39978e6b599 OK 2025/03/14 06:29:54 INFO : only2: Copied (replaced existing) 2025/03/14 06:29:54 DEBUG : only4: md5 = 806d8d714d094c3189062c4900995785 OK 2025/03/14 06:29:54 INFO : only4: Copied (replaced existing) 2025/03/14 06:29:54 DEBUG : only5: md5 = c3580ded4eee48f9e89ddfc2bfc0a20b OK 2025/03/14 06:29:54 INFO : only5: Copied (replaced existing) 2025/03/14 06:29:55 DEBUG : only6: md5 = a0defa723f50384f719739a14a9e944c OK 2025/03/14 06:29:55 INFO : only6: Copied (replaced existing) 2025/03/14 06:29:55 DEBUG : only7: md5 = 110a531eaa0868b869f62f97e70a0993 OK 2025/03/14 06:29:55 INFO : only7: Copied (replaced existing) 2025/03/14 06:29:55 DEBUG : only8: md5 = e693e68551a0faad80b8ac0c56ec5c77 OK 2025/03/14 06:29:55 INFO : only8: Copied (replaced existing) 2025/03/14 06:29:55 DEBUG : only9: md5 = 8ccb40759c2a88167a2a764538a74a52 OK 2025/03/14 06:29:55 INFO : only9: Copied (replaced existing) 2025/03/14 06:29:55 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-bebopij4liga'", Local "Local file system at /tmp/rclone492104059", Modify Window "1ms" --- PASS: TestSyncConcurrentTruncate (80.79s) === RUN TestSyncReplaceDirModTime run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-bebopij4liga'", Local "Local file system at /tmp/rclone492104059", Modify Window "1ms" 2025/03/14 06:30:15 DEBUG : empty_dir: Making directory with metadata 2025/03/14 06:30:15 INFO : empty_dir: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2025/03/14 06:30:15 DEBUG : empty_on_remote: Making directory with metadata 2025/03/14 06:30:15 INFO : empty_on_remote: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2025/03/14 06:30:15 DEBUG : empty_on_remote: Making directory with metadata 2025/03/14 06:30:15 INFO : empty_on_remote: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-bebopij4liga'", Local "Local file system at /tmp/rclone492104059", Modify Window "1ms" 2025/03/14 06:30:21 INFO : test_dir1: Set directory modification time (using DirSetModTime) 2025/03/14 06:30:21 INFO : test_dir2: Set directory modification time (using DirSetModTime) 2025/03/14 06:30:21 INFO : test_dir2/sub_dir: Set directory modification time (using DirSetModTime) 2025/03/14 06:30:21 INFO : empty_on_remote: Set directory modification time (using DirSetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-bebopij4liga'", Local "Local file system at /tmp/rclone492104059", Modify Window "1ms" 2025/03/14 06:30:28 DEBUG : heqj02jg0dcqlem7gl0500bvp0/24g2k8bseitblkmqnie1ibl2s8: Rmdir: contains trashed file: "633fmaa0qic3kv3cladnu11pto" 2025/03/14 06:30:28 DEBUG : heqj02jg0dcqlem7gl0500bvp0: Rmdir: contains trashed file: "24g2k8bseitblkmqnie1ibl2s8" 2025/03/14 06:30:29 DEBUG : gq68srrpl0nnf394bgf7dbu9kc: Rmdir: contains trashed file: "d26uovf0miqhd1mu3c9jbseq00" --- PASS: TestSyncReplaceDirModTime (16.57s) === RUN TestSyncReplaceDirModTimeWithEmptyDirs run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-bebopij4liga'", Local "Local file system at /tmp/rclone492104059", Modify Window "1ms" 2025/03/14 06:30:31 DEBUG : empty_dir: Making directory with metadata 2025/03/14 06:30:31 INFO : empty_dir: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2025/03/14 06:30:31 DEBUG : empty_on_remote: Making directory with metadata 2025/03/14 06:30:31 INFO : empty_on_remote: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2025/03/14 06:30:31 DEBUG : empty_on_remote: Making directory with metadata 2025/03/14 06:30:32 INFO : empty_on_remote: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-bebopij4liga'", Local "Local file system at /tmp/rclone492104059", Modify Window "1ms" 2025/03/14 06:30:37 INFO : test_dir1: Set directory modification time (using DirSetModTime) 2025/03/14 06:30:37 INFO : test_dir2: Set directory modification time (using DirSetModTime) 2025/03/14 06:30:37 INFO : test_dir2/sub_dir: Set directory modification time (using DirSetModTime) 2025/03/14 06:30:37 INFO : empty_on_remote: Set directory modification time (using DirSetModTime) 2025/03/14 06:30:37 INFO : empty_dir: Set directory modification time (using DirSetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-bebopij4liga'", Local "Local file system at /tmp/rclone492104059", Modify Window "1ms" 2025/03/14 06:30:45 DEBUG : heqj02jg0dcqlem7gl0500bvp0/24g2k8bseitblkmqnie1ibl2s8: Rmdir: contains trashed file: "633fmaa0qic3kv3cladnu11pto" 2025/03/14 06:30:45 DEBUG : heqj02jg0dcqlem7gl0500bvp0: Rmdir: contains trashed file: "24g2k8bseitblkmqnie1ibl2s8" 2025/03/14 06:30:46 DEBUG : gq68srrpl0nnf394bgf7dbu9kc: Rmdir: contains trashed file: "d26uovf0miqhd1mu3c9jbseq00" --- PASS: TestSyncReplaceDirModTimeWithEmptyDirs (17.82s) === RUN TestNothingToTransferWithEmptyDirs run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-bebopij4liga'", Local "Local file system at /tmp/rclone492104059", Modify Window "1ms" 2025/03/14 06:30:49 INFO : sub dir: Set directory modification time (using DirSetModTime) 2025/03/14 06:30:49 DEBUG : sub dir: Making directory with metadata 2025/03/14 06:30:50 INFO : sub dir: Made directory with metadata (mtime=2011-12-30T12:59:59Z) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-bebopij4liga'", Local "Local file system at /tmp/rclone492104059", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-bebopij4liga'", Local "Local file system at /tmp/rclone492104059", Modify Window "1ms" 2025/03/14 06:31:08 INFO : sub dir2: Set directory modification time (using DirSetModTime) 2025/03/14 06:31:09 INFO : sub dir2: Set directory modification time (using DirSetModTime) 2025/03/14 06:31:09 INFO : sub dirEmpty/sub dirEmpty2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2025/03/14 06:31:09 INFO : sub dirEmpty: Set directory modification time (using DirSetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-bebopij4liga'", Local "Local file system at /tmp/rclone492104059", Modify Window "1ms" 2025/03/14 06:31:22 DEBUG : gcsdkq814sbtppue42dpsbg8ug: Rmdir: contains trashed file: "sjuo65gk5q3r1199jselk9k9o0" 2025/03/14 06:31:22 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/37qp6d1gohacv723ij3brofbu8/i24n0ln37pa2hv8pctddeuh73o: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" 2025/03/14 06:31:23 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/37qp6d1gohacv723ij3brofbu8: Rmdir: contains trashed file: "i24n0ln37pa2hv8pctddeuh73o" 2025/03/14 06:31:24 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "37qp6d1gohacv723ij3brofbu8" 2025/03/14 06:31:24 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak" 2025/03/14 06:31:25 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak" 2025/03/14 06:31:26 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak" 2025/03/14 06:31:27 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak" 2025/03/14 06:31:27 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/4r13oncfa2rsrr82oqhsqv24ns: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" 2025/03/14 06:31:28 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc: Rmdir: contains trashed file: "4r13oncfa2rsrr82oqhsqv24ns" 2025/03/14 06:31:28 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak" 2025/03/14 06:31:29 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestNothingToTransferWithEmptyDirs (41.64s) === RUN TestNothingToTransferWithoutEmptyDirs run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-bebopij4liga'", Local "Local file system at /tmp/rclone492104059", Modify Window "1ms" 2025/03/14 06:31:31 INFO : sub dir: Set directory modification time (using DirSetModTime) 2025/03/14 06:31:31 DEBUG : sub dir: Making directory with metadata 2025/03/14 06:31:31 INFO : sub dir: Made directory with metadata (mtime=2011-12-30T12:59:59Z) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-bebopij4liga'", Local "Local file system at /tmp/rclone492104059", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-bebopij4liga'", Local "Local file system at /tmp/rclone492104059", Modify Window "1ms" 2025/03/14 06:31:54 INFO : sub dir2: Set directory modification time (using DirSetModTime) 2025/03/14 06:31:54 INFO : sub dir2: Set directory modification time (using DirSetModTime) 2025/03/14 06:31:54 INFO : sub dirEmpty/sub dirEmpty2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2025/03/14 06:31:54 INFO : sub dirEmpty: Set directory modification time (using DirSetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-bebopij4liga'", Local "Local file system at /tmp/rclone492104059", Modify Window "1ms" 2025/03/14 06:32:06 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/37qp6d1gohacv723ij3brofbu8/i24n0ln37pa2hv8pctddeuh73o: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" 2025/03/14 06:32:07 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/37qp6d1gohacv723ij3brofbu8: Rmdir: contains trashed file: "i24n0ln37pa2hv8pctddeuh73o" 2025/03/14 06:32:07 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "37qp6d1gohacv723ij3brofbu8" 2025/03/14 06:32:08 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak" 2025/03/14 06:32:09 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak" 2025/03/14 06:32:10 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak" 2025/03/14 06:32:10 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak" 2025/03/14 06:32:11 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/4r13oncfa2rsrr82oqhsqv24ns: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" 2025/03/14 06:32:12 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc: Rmdir: contains trashed file: "4r13oncfa2rsrr82oqhsqv24ns" 2025/03/14 06:32:12 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak" 2025/03/14 06:32:12 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestNothingToTransferWithoutEmptyDirs (43.85s) PASS 2025/03/14 06:32:15 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-bebopij4liga': Purge remote "./sync.test -test.v -test.timeout 1h0m0s -remote TestCryptDrive: -verbose" - Finished OK in 16m4.120137146s (try 1/5)