"./sync.test -test.v -test.timeout 1h0m0s -remote TestCryptDrive: -verbose -fast-list" - Starting (try 1/5) 2025/05/04 05:41:02 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-dozoqax1kegu" 2025/05/04 05:41:02 DEBUG : Using config file from "/home/rclone/.rclone.conf" 2025/05/04 05:41:02 DEBUG : Creating backend with remote "TestDrive:crypt/cpul26lr8ek8vhk8j66soansr0gvmba19g0oli717lmu0de2ir60" 2025/05/04 05:41:03 DEBUG : Creating backend with remote "/tmp/rclone3598271736" === RUN TestPipe --- PASS: TestPipe (0.00s) === RUN TestPipeConcurrent --- PASS: TestPipeConcurrent (0.05s) === RUN TestPipeOrderBy === RUN TestPipeOrderBy/#00 === RUN TestPipeOrderBy/size === RUN TestPipeOrderBy/name === RUN TestPipeOrderBy/modtime === RUN TestPipeOrderBy/size,ascending === RUN TestPipeOrderBy/name,asc === RUN TestPipeOrderBy/modtime,ascending === RUN TestPipeOrderBy/size,descending === RUN TestPipeOrderBy/name,desc === RUN TestPipeOrderBy/modtime,descending === RUN TestPipeOrderBy/size,mixed,50 === RUN TestPipeOrderBy/size,mixed,51 --- PASS: TestPipeOrderBy (0.00s) --- PASS: TestPipeOrderBy/#00 (0.00s) --- PASS: TestPipeOrderBy/size (0.00s) --- PASS: TestPipeOrderBy/name (0.00s) --- PASS: TestPipeOrderBy/modtime (0.00s) --- PASS: TestPipeOrderBy/size,ascending (0.00s) --- PASS: TestPipeOrderBy/name,asc (0.00s) --- PASS: TestPipeOrderBy/modtime,ascending (0.00s) --- PASS: TestPipeOrderBy/size,descending (0.00s) --- PASS: TestPipeOrderBy/name,desc (0.00s) --- PASS: TestPipeOrderBy/modtime,descending (0.00s) --- PASS: TestPipeOrderBy/size,mixed,50 (0.00s) --- PASS: TestPipeOrderBy/size,mixed,51 (0.00s) === RUN TestNewLess === RUN TestNewLess/blankOK === RUN TestNewLess/tooManyParts === RUN TestNewLess/tooManyParts2 === RUN TestNewLess/badMixed === RUN TestNewLess/unknownComparison === RUN TestNewLess/unknownSortDirection === RUN TestNewLess/size === RUN TestNewLess/name === RUN TestNewLess/modtime === RUN TestNewLess/size,ascending === RUN TestNewLess/name,asc === RUN TestNewLess/modtime,ascending === RUN TestNewLess/size,descending === RUN TestNewLess/name,desc === RUN TestNewLess/modtime,descending === RUN TestNewLess/modtime,mixed === RUN TestNewLess/modtime,mixed,30 --- PASS: TestNewLess (0.00s) --- PASS: TestNewLess/blankOK (0.00s) --- PASS: TestNewLess/tooManyParts (0.00s) --- PASS: TestNewLess/tooManyParts2 (0.00s) --- PASS: TestNewLess/badMixed (0.00s) --- PASS: TestNewLess/unknownComparison (0.00s) --- PASS: TestNewLess/unknownSortDirection (0.00s) --- PASS: TestNewLess/size (0.00s) --- PASS: TestNewLess/name (0.00s) --- PASS: TestNewLess/modtime (0.00s) --- PASS: TestNewLess/size,ascending (0.00s) --- PASS: TestNewLess/name,asc (0.00s) --- PASS: TestNewLess/modtime,ascending (0.00s) --- PASS: TestNewLess/size,descending (0.00s) --- PASS: TestNewLess/name,desc (0.00s) --- PASS: TestNewLess/modtime,descending (0.00s) --- PASS: TestNewLess/modtime,mixed (0.00s) --- PASS: TestNewLess/modtime,mixed,30 (0.00s) === RUN TestRcCopy rc_test.go:16: Skipping test on non local remote --- SKIP: TestRcCopy (0.00s) === RUN TestRcMove rc_test.go:16: Skipping test on non local remote --- SKIP: TestRcMove (0.00s) === RUN TestRcSync rc_test.go:16: Skipping test on non local remote --- SKIP: TestRcSync (0.00s) === RUN TestCopyWithDryRun run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dozoqax1kegu'", Local "Local file system at /tmp/rclone3598271736", Modify Window "1ms" 2025/05/04 05:41:04 DEBUG : Added delayed dir = "sub dir", newDst= 2025/05/04 05:41:04 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2025/05/04 05:41:04 NOTICE: sub dir/hello world: Skipped copy as --dry-run is set (size 11) 2025/05/04 05:41:04 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dozoqax1kegu': Waiting for checks to finish 2025/05/04 05:41:04 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dozoqax1kegu': Waiting for transfers to finish 2025/05/04 05:41:04 NOTICE: sub dir: Skipped set directory modification time as --dry-run is set run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dozoqax1kegu'", Local "Local file system at /tmp/rclone3598271736", Modify Window "1ms" --- PASS: TestCopyWithDryRun (2.01s) === RUN TestCopy run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dozoqax1kegu'", Local "Local file system at /tmp/rclone3598271736", Modify Window "1ms" 2025/05/04 05:41:05 INFO : sub dir: Set directory modification time (using DirSetModTime) 2025/05/04 05:41:05 DEBUG : Added delayed dir = "sub dir", newDst= 2025/05/04 05:41:05 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2025/05/04 05:41:05 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dozoqax1kegu': Waiting for checks to finish 2025/05/04 05:41:05 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dozoqax1kegu': Waiting for transfers to finish 2025/05/04 05:41:07 DEBUG : sub dir/hello world: md5 = 0358174cfa5daad4649b5db8ed2813e7 OK 2025/05/04 05:41:07 INFO : sub dir/hello world: Copied (new) 2025/05/04 05:41:07 INFO : sub dir: Set directory modification time (using DirSetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dozoqax1kegu'", Local "Local file system at /tmp/rclone3598271736", Modify Window "1ms" 2025/05/04 05:41:09 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestCopy (5.45s) === RUN TestCopyMetadata run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dozoqax1kegu'", Local "Local file system at /tmp/rclone3598271736", Modify Window "1ms" 2025/05/04 05:41:10 DEBUG : metadata sub dir: Making directory with metadata 2025/05/04 05:41:10 INFO : metadata sub dir: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2025/05/04 05:41:10 DEBUG : empty metadata sub dir: Making directory with metadata 2025/05/04 05:41:10 INFO : empty metadata sub dir: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2025/05/04 05:41:10 DEBUG : Local file system at /tmp/rclone3598271736: File to upload is small (21 bytes), uploading instead of streaming 2025/05/04 05:41:10 DEBUG : metadata sub dir/hello metadata world: md5 = baa7a013449dbba2b1ed02b5cfb4e1a2 OK 2025/05/04 05:41:10 DEBUG : metadata sub dir/hello metadata world: Size and md5 of src and dst objects identical 2025/05/04 05:41:10 INFO : metadata sub dir: Set directory modification time (using DirSetModTime) 2025/05/04 05:41:11 DEBUG : Google drive root 'crypt/cpul26lr8ek8vhk8j66soansr0gvmba19g0oli717lmu0de2ir60': Skipping btime metadata as can't update it on an existing file: 2025-05-04T05:41:10.708806009Z 2025/05/04 05:41:11 INFO : empty metadata sub dir: Updated directory metadata 2025/05/04 05:41:11 DEBUG : Google drive root 'crypt/cpul26lr8ek8vhk8j66soansr0gvmba19g0oli717lmu0de2ir60': Skipping btime metadata as can't update it on an existing file: 2025-05-04T05:41:10.708806009Z 2025/05/04 05:41:12 INFO : metadata sub dir: Updated directory metadata 2025/05/04 05:41:12 DEBUG : metadata sub dir/hello metadata world: Need to transfer - File not found at Destination 2025/05/04 05:41:12 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dozoqax1kegu': Waiting for checks to finish 2025/05/04 05:41:12 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dozoqax1kegu': Waiting for transfers to finish 2025/05/04 05:41:13 DEBUG : metadata sub dir/hello metadata world: md5 = f2b17c08e97701871006a3e6e81ca38d OK 2025/05/04 05:41:13 INFO : metadata sub dir/hello metadata world: Copied (new) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dozoqax1kegu'", Local "Local file system at /tmp/rclone3598271736", Modify Window "1ms" 2025/05/04 05:41:16 DEBUG : fg45q1rm3kh00nmmkk4m6ihmrcnel1p7551kqhjr9bk2gtd2gbf0: Rmdir: contains trashed file: "dmuvulfij81f693ur0f1vvbvq9v6iscp56daas3m51n9li5e3470" --- PASS: TestCopyMetadata (7.28s) === RUN TestCopyMetadataNoEmptyDirs run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dozoqax1kegu'", Local "Local file system at /tmp/rclone3598271736", Modify Window "1ms" 2025/05/04 05:41:17 DEBUG : metadata sub dir: Making directory with metadata 2025/05/04 05:41:17 INFO : metadata sub dir: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2025/05/04 05:41:17 DEBUG : empty metadata sub dir: Making directory with metadata 2025/05/04 05:41:17 INFO : empty metadata sub dir: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2025/05/04 05:41:17 DEBUG : Local file system at /tmp/rclone3598271736: File to upload is small (21 bytes), uploading instead of streaming 2025/05/04 05:41:17 DEBUG : metadata sub dir/hello metadata world: md5 = baa7a013449dbba2b1ed02b5cfb4e1a2 OK 2025/05/04 05:41:17 DEBUG : metadata sub dir/hello metadata world: Size and md5 of src and dst objects identical 2025/05/04 05:41:17 INFO : metadata sub dir: Set directory modification time (using DirSetModTime) 2025/05/04 05:41:18 DEBUG : Added delayed dir = "empty metadata sub dir", newDst= 2025/05/04 05:41:18 DEBUG : Added delayed dir = "metadata sub dir", newDst= 2025/05/04 05:41:18 DEBUG : metadata sub dir/hello metadata world: Need to transfer - File not found at Destination 2025/05/04 05:41:18 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dozoqax1kegu': Waiting for checks to finish 2025/05/04 05:41:18 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dozoqax1kegu': Waiting for transfers to finish 2025/05/04 05:41:20 DEBUG : metadata sub dir/hello metadata world: md5 = bc6bd9671ec3a2870c75d42d6e37b881 OK 2025/05/04 05:41:20 INFO : metadata sub dir/hello metadata world: Copied (new) 2025/05/04 05:41:20 DEBUG : Google drive root 'crypt/cpul26lr8ek8vhk8j66soansr0gvmba19g0oli717lmu0de2ir60': Skipping btime metadata as can't update it on an existing file: 2025-05-04T05:41:17.988816077Z 2025/05/04 05:41:20 INFO : metadata sub dir: Updated directory metadata run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dozoqax1kegu'", Local "Local file system at /tmp/rclone3598271736", Modify Window "1ms" 2025/05/04 05:41:23 DEBUG : fg45q1rm3kh00nmmkk4m6ihmrcnel1p7551kqhjr9bk2gtd2gbf0: Rmdir: contains trashed file: "dmuvulfij81f693ur0f1vvbvq9v6iscp56daas3m51n9li5e3470" --- PASS: TestCopyMetadataNoEmptyDirs (6.28s) === RUN TestCopyMissingDirectory run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dozoqax1kegu'", Local "Local file system at /tmp/rclone3598271736", Modify Window "1ms" 2025/05/04 05:41:24 DEBUG : Creating backend with remote "/non-existing" 2025/05/04 05:41:24 ERROR : Local file system at /non-existing: error reading source root directory: directory not found 2025/05/04 05:41:24 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dozoqax1kegu': Waiting for checks to finish 2025/05/04 05:41:24 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dozoqax1kegu': Waiting for transfers to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dozoqax1kegu'", Local "Local file system at /tmp/rclone3598271736", Modify Window "1ms" --- PASS: TestCopyMissingDirectory (1.11s) === RUN TestCopyNoTraverse run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dozoqax1kegu'", Local "Local file system at /tmp/rclone3598271736", Modify Window "1ms" 2025/05/04 05:41:25 DEBUG : Added delayed dir = "sub dir", newDst= 2025/05/04 05:41:25 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2025/05/04 05:41:25 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dozoqax1kegu': Waiting for checks to finish 2025/05/04 05:41:25 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dozoqax1kegu': Waiting for transfers to finish 2025/05/04 05:41:27 DEBUG : sub dir/hello world: md5 = ccd6695d35d1ca48c2ea3231a0e0aad8 OK 2025/05/04 05:41:27 INFO : sub dir/hello world: Copied (new) 2025/05/04 05:41:27 INFO : sub dir: Set directory modification time (using DirSetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dozoqax1kegu'", Local "Local file system at /tmp/rclone3598271736", Modify Window "1ms" 2025/05/04 05:41:30 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestCopyNoTraverse (6.18s) === RUN TestCopyCheckFirst run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dozoqax1kegu'", Local "Local file system at /tmp/rclone3598271736", Modify Window "1ms" 2025/05/04 05:41:31 INFO : Encrypted drive 'TestCryptDrive:rclone-test-dozoqax1kegu': Running all checks before starting transfers 2025/05/04 05:41:31 DEBUG : Added delayed dir = "sub dir", newDst= 2025/05/04 05:41:31 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2025/05/04 05:41:31 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dozoqax1kegu': Waiting for checks to finish 2025/05/04 05:41:31 INFO : Encrypted drive 'TestCryptDrive:rclone-test-dozoqax1kegu': Checks finished, now starting transfers 2025/05/04 05:41:31 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dozoqax1kegu': Waiting for transfers to finish 2025/05/04 05:41:33 DEBUG : sub dir/hello world: md5 = 52e7f6f3a68e140cab4d86de86f9aa89 OK 2025/05/04 05:41:33 INFO : sub dir/hello world: Copied (new) 2025/05/04 05:41:34 INFO : sub dir: Set directory modification time (using DirSetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dozoqax1kegu'", Local "Local file system at /tmp/rclone3598271736", Modify Window "1ms" 2025/05/04 05:41:36 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestCopyCheckFirst (5.62s) === RUN TestSyncNoTraverse run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dozoqax1kegu'", Local "Local file system at /tmp/rclone3598271736", Modify Window "1ms" 2025/05/04 05:41:37 ERROR : Ignoring --no-traverse with sync 2025/05/04 05:41:37 DEBUG : Added delayed dir = "sub dir", newDst= 2025/05/04 05:41:37 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2025/05/04 05:41:37 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dozoqax1kegu': Waiting for checks to finish 2025/05/04 05:41:37 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dozoqax1kegu': Waiting for transfers to finish 2025/05/04 05:41:39 DEBUG : sub dir/hello world: md5 = 04153cc9add43cae4b73c67d988a8512 OK 2025/05/04 05:41:39 INFO : sub dir/hello world: Copied (new) 2025/05/04 05:41:39 DEBUG : Waiting for deletions to finish 2025/05/04 05:41:39 INFO : sub dir: Set directory modification time (using DirSetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dozoqax1kegu'", Local "Local file system at /tmp/rclone3598271736", Modify Window "1ms" 2025/05/04 05:41:41 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestSyncNoTraverse (5.53s) === RUN TestCopyWithDepth run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dozoqax1kegu'", Local "Local file system at /tmp/rclone3598271736", Modify Window "1ms" 2025/05/04 05:41:42 DEBUG : hello world2: Need to transfer - File not found at Destination 2025/05/04 05:41:42 DEBUG : Added delayed dir = "sub dir", newDst= 2025/05/04 05:41:42 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dozoqax1kegu': Waiting for checks to finish 2025/05/04 05:41:42 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dozoqax1kegu': Waiting for transfers to finish 2025/05/04 05:41:44 DEBUG : hello world2: md5 = 538b60f3445f22f7fb982b45b7d345cf OK 2025/05/04 05:41:44 INFO : hello world2: Copied (new) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dozoqax1kegu'", Local "Local file system at /tmp/rclone3598271736", Modify Window "1ms" --- PASS: TestCopyWithDepth (3.15s) === RUN TestCopyWithFilesFrom run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dozoqax1kegu'", Local "Local file system at /tmp/rclone3598271736", Modify Window "1ms" 2025/05/04 05:41:46 DEBUG : potato2: Need to transfer - File not found at Destination 2025/05/04 05:41:46 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dozoqax1kegu': Waiting for checks to finish 2025/05/04 05:41:46 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dozoqax1kegu': Waiting for transfers to finish 2025/05/04 05:41:47 DEBUG : potato2: md5 = 8ab0d1d4f5fe8445a7b19ddf8d63072a OK 2025/05/04 05:41:47 INFO : potato2: Copied (new) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dozoqax1kegu'", Local "Local file system at /tmp/rclone3598271736", Modify Window "1ms" --- PASS: TestCopyWithFilesFrom (3.19s) === RUN TestCopyWithFilesFromAndNoTraverse run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dozoqax1kegu'", Local "Local file system at /tmp/rclone3598271736", Modify Window "1ms" 2025/05/04 05:41:49 DEBUG : potato2: Need to transfer - File not found at Destination 2025/05/04 05:41:49 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dozoqax1kegu': Waiting for checks to finish 2025/05/04 05:41:49 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dozoqax1kegu': Waiting for transfers to finish 2025/05/04 05:41:50 DEBUG : potato2: md5 = a0fb689e5986f6abf89c3cdf771e962c OK 2025/05/04 05:41:50 INFO : potato2: Copied (new) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dozoqax1kegu'", Local "Local file system at /tmp/rclone3598271736", Modify Window "1ms" --- PASS: TestCopyWithFilesFromAndNoTraverse (3.09s) === RUN TestCopyEmptyDirectories run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dozoqax1kegu'", Local "Local file system at /tmp/rclone3598271736", Modify Window "1ms" 2025/05/04 05:41:52 DEBUG : sub dir2/sub sub dir2: Making directory with metadata 2025/05/04 05:41:52 INFO : sub dir2/sub sub dir2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2025/05/04 05:41:52 INFO : sub dir2: Set directory modification time (using DirSetModTime) 2025/05/04 05:41:52 INFO : sub dir: Set directory modification time (using DirSetModTime) 2025/05/04 05:41:52 DEBUG : sub dir: Making directory with metadata 2025/05/04 05:41:53 INFO : sub dir: Made directory with metadata (mtime=2001-02-03T04:05:06.499999999Z) 2025/05/04 05:41:53 DEBUG : sub dir2: Making directory with metadata 2025/05/04 05:41:53 INFO : sub dir2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2025/05/04 05:41:53 DEBUG : sub dir2/sub sub dir2: Making directory with metadata 2025/05/04 05:41:53 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2025/05/04 05:41:54 INFO : sub dir2/sub sub dir2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2025/05/04 05:41:54 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dozoqax1kegu': Waiting for checks to finish 2025/05/04 05:41:54 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dozoqax1kegu': Waiting for transfers to finish 2025/05/04 05:41:55 DEBUG : sub dir/hello world: md5 = 6ddc1b17d581d741155164945d25bc05 OK 2025/05/04 05:41:55 INFO : sub dir/hello world: Copied (new) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dozoqax1kegu'", Local "Local file system at /tmp/rclone3598271736", Modify Window "1ms" 2025/05/04 05:41:58 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc: Rmdir: contains trashed file: "cv6a9uf28ngrajena8kt5ijjn0" 2025/05/04 05:41:59 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestCopyEmptyDirectories (8.41s) === RUN TestCopyNoEmptyDirectories run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dozoqax1kegu'", Local "Local file system at /tmp/rclone3598271736", Modify Window "1ms" 2025/05/04 05:42:00 INFO : sub dir2: Making directory 2025/05/04 05:42:00 DEBUG : sub dir2/sub sub dir2: Making directory with metadata 2025/05/04 05:42:00 INFO : sub dir2/sub sub dir2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2025/05/04 05:42:00 DEBUG : Added delayed dir = "sub dir", newDst= 2025/05/04 05:42:00 DEBUG : Added delayed dir = "sub dir2", newDst= 2025/05/04 05:42:00 DEBUG : Added delayed dir = "sub dir2/sub sub dir2", newDst= 2025/05/04 05:42:00 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2025/05/04 05:42:00 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dozoqax1kegu': Waiting for checks to finish 2025/05/04 05:42:00 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dozoqax1kegu': Waiting for transfers to finish 2025/05/04 05:42:02 DEBUG : sub dir/hello world: md5 = 182e76a52f80a7941830d6c923668e2b OK 2025/05/04 05:42:02 INFO : sub dir/hello world: Copied (new) 2025/05/04 05:42:03 INFO : sub dir: Set directory modification time (using DirSetModTime) 2025/05/04 05:42:04 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestCopyNoEmptyDirectories (5.04s) === RUN TestMoveEmptyDirectories run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dozoqax1kegu'", Local "Local file system at /tmp/rclone3598271736", Modify Window "1ms" 2025/05/04 05:42:05 DEBUG : sub dir2: Making directory with metadata 2025/05/04 05:42:05 INFO : sub dir2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2025/05/04 05:42:05 DEBUG : sub dir: Making directory with metadata 2025/05/04 05:42:06 INFO : sub dir: Made directory with metadata (mtime=2025-05-04T05:42:05.588881891Z) 2025/05/04 05:42:06 DEBUG : sub dir2: Making directory with metadata 2025/05/04 05:42:07 INFO : sub dir2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2025/05/04 05:42:07 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2025/05/04 05:42:07 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dozoqax1kegu': Waiting for checks to finish 2025/05/04 05:42:07 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dozoqax1kegu': Waiting for transfers to finish 2025/05/04 05:42:08 DEBUG : sub dir/hello world: md5 = 33d6116198590a6fe787c504af2e2240 OK 2025/05/04 05:42:08 INFO : sub dir/hello world: Copied (new) 2025/05/04 05:42:08 INFO : sub dir/hello world: Deleted run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dozoqax1kegu'", Local "Local file system at /tmp/rclone3598271736", Modify Window "1ms" 2025/05/04 05:42:11 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestMoveEmptyDirectories (7.14s) === RUN TestSyncNoUpdateDirModtime run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dozoqax1kegu'", Local "Local file system at /tmp/rclone3598271736", Modify Window "1ms" 2025/05/04 05:42:12 DEBUG : sub dir no update dir modtime: Making directory with metadata 2025/05/04 05:42:12 INFO : sub dir no update dir modtime: Made directory with metadata (mtime=2001-02-03T04:05:06.499999999Z) 2025/05/04 05:42:14 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dozoqax1kegu': Waiting for checks to finish 2025/05/04 05:42:14 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dozoqax1kegu': Waiting for transfers to finish 2025/05/04 05:42:14 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dozoqax1kegu'", Local "Local file system at /tmp/rclone3598271736", Modify Window "1ms" --- PASS: TestSyncNoUpdateDirModtime (3.79s) === RUN TestMoveNoEmptyDirectories run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dozoqax1kegu'", Local "Local file system at /tmp/rclone3598271736", Modify Window "1ms" 2025/05/04 05:42:16 INFO : sub dir2: Making directory 2025/05/04 05:42:16 DEBUG : Added delayed dir = "sub dir", newDst= 2025/05/04 05:42:16 DEBUG : Added delayed dir = "sub dir2", newDst= 2025/05/04 05:42:16 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2025/05/04 05:42:16 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dozoqax1kegu': Waiting for checks to finish 2025/05/04 05:42:16 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dozoqax1kegu': Waiting for transfers to finish 2025/05/04 05:42:18 DEBUG : sub dir/hello world: md5 = 21455bf9df54b77dceaa8971b20ce8b5 OK 2025/05/04 05:42:18 INFO : sub dir/hello world: Copied (new) 2025/05/04 05:42:18 INFO : sub dir/hello world: Deleted 2025/05/04 05:42:19 INFO : sub dir: Set directory modification time (using DirSetModTime) 2025/05/04 05:42:21 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestMoveNoEmptyDirectories (5.22s) === RUN TestSyncEmptyDirectories run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dozoqax1kegu'", Local "Local file system at /tmp/rclone3598271736", Modify Window "1ms" 2025/05/04 05:42:21 DEBUG : sub dir2: Making directory with metadata 2025/05/04 05:42:21 INFO : sub dir2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2025/05/04 05:42:21 INFO : sub dir: Set directory modification time (using DirSetModTime) 2025/05/04 05:42:21 DEBUG : sub dir: Making directory with metadata 2025/05/04 05:42:22 INFO : sub dir: Made directory with metadata (mtime=2001-02-03T04:05:06.499999999Z) 2025/05/04 05:42:22 DEBUG : sub dir2: Making directory with metadata 2025/05/04 05:42:23 INFO : sub dir2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2025/05/04 05:42:23 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2025/05/04 05:42:23 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dozoqax1kegu': Waiting for checks to finish 2025/05/04 05:42:23 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dozoqax1kegu': Waiting for transfers to finish 2025/05/04 05:42:24 DEBUG : sub dir/hello world: md5 = fb659d8ae704c1967188cbcd1afd8d03 OK 2025/05/04 05:42:24 INFO : sub dir/hello world: Copied (new) 2025/05/04 05:42:24 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dozoqax1kegu'", Local "Local file system at /tmp/rclone3598271736", Modify Window "1ms" 2025/05/04 05:42:27 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestSyncEmptyDirectories (6.79s) === RUN TestSyncSetDelayedModTimes run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dozoqax1kegu'", Local "Local file system at /tmp/rclone3598271736", Modify Window "1ms" sync_test.go:507: Backend doesn't have DirModTimeUpdatesOnWrite set --- SKIP: TestSyncSetDelayedModTimes (0.42s) === RUN TestSyncNoEmptyDirectories run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dozoqax1kegu'", Local "Local file system at /tmp/rclone3598271736", Modify Window "1ms" 2025/05/04 05:42:28 INFO : sub dir2: Making directory 2025/05/04 05:42:29 DEBUG : Added delayed dir = "sub dir", newDst= 2025/05/04 05:42:29 DEBUG : Added delayed dir = "sub dir2", newDst= 2025/05/04 05:42:29 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2025/05/04 05:42:29 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dozoqax1kegu': Waiting for checks to finish 2025/05/04 05:42:29 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dozoqax1kegu': Waiting for transfers to finish 2025/05/04 05:42:31 DEBUG : sub dir/hello world: md5 = 2c4b3926156fd0f9c6753304550a32bf OK 2025/05/04 05:42:31 INFO : sub dir/hello world: Copied (new) 2025/05/04 05:42:31 DEBUG : Waiting for deletions to finish 2025/05/04 05:42:31 INFO : sub dir: Set directory modification time (using DirSetModTime) 2025/05/04 05:42:33 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestSyncNoEmptyDirectories (4.98s) === RUN TestServerSideCopy run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dozoqax1kegu'", Local "Local file system at /tmp/rclone3598271736", Modify Window "1ms" 2025/05/04 05:42:35 DEBUG : sub dir/hello world: md5 = fc2d5139cd0d82f7484a7a597618b184 OK 2025/05/04 05:42:36 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-lujafob2xaga" 2025/05/04 05:42:36 DEBUG : Creating backend with remote "TestDrive:crypt/g9oeakmj1svfiatqbte0dkldr73pl527fkrmd1mdd8mecg2bkc00" sync_test.go:590: Server side copy (if possible) Encrypted drive 'TestCryptDrive:rclone-test-dozoqax1kegu' -> Encrypted drive 'TestCryptDrive:rclone-test-lujafob2xaga' 2025/05/04 05:42:37 DEBUG : Added delayed dir = "sub dir", newDst= 2025/05/04 05:42:37 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2025/05/04 05:42:37 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-lujafob2xaga': Waiting for checks to finish 2025/05/04 05:42:37 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-lujafob2xaga': Waiting for transfers to finish 2025/05/04 05:42:40 INFO : sub dir/hello world: Copied (server-side copy) 2025/05/04 05:42:40 INFO : sub dir: Set directory modification time (using DirSetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dozoqax1kegu'", Local "Local file system at /tmp/rclone3598271736", Modify Window "1ms" 2025/05/04 05:42:41 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-lujafob2xaga': Purge remote 2025/05/04 05:42:42 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestServerSideCopy (9.97s) === RUN TestCopyOverSelf run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dozoqax1kegu'", Local "Local file system at /tmp/rclone3598271736", Modify Window "1ms" 2025/05/04 05:42:46 DEBUG : sub dir/hello world: md5 = a908f2555ae46fff003e0895347439b9 OK 2025/05/04 05:42:47 INFO : sub dir: Set directory modification time (using SetModTime) 2025/05/04 05:42:47 DEBUG : Added delayed dir = "sub dir", newDst=sub dir 2025/05/04 05:42:47 DEBUG : sub dir/hello world: Sizes differ (src 17 vs dst 11) 2025/05/04 05:42:47 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dozoqax1kegu': Waiting for checks to finish 2025/05/04 05:42:47 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dozoqax1kegu': Waiting for transfers to finish 2025/05/04 05:42:48 DEBUG : sub dir/hello world: md5 = a5ca65ec86fe3477ce5bad7953952b77 OK 2025/05/04 05:42:48 INFO : sub dir/hello world: Copied (replaced existing) 2025/05/04 05:42:48 INFO : sub dir: Set directory modification time (using SetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dozoqax1kegu'", Local "Local file system at /tmp/rclone3598271736", Modify Window "1ms" 2025/05/04 05:42:50 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestCopyOverSelf (7.91s) === RUN TestServerSideCopyOverSelf run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dozoqax1kegu'", Local "Local file system at /tmp/rclone3598271736", Modify Window "1ms" 2025/05/04 05:42:53 DEBUG : sub dir/hello world: md5 = 756e48b10c48ec46de248b67923d2d8e OK 2025/05/04 05:42:54 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-yozebuj9yude" 2025/05/04 05:42:54 DEBUG : Creating backend with remote "TestDrive:crypt/n5amri0l0d4kda4gph6tfbiqq91uq7b38h5b757j7trm405bd9cg" sync_test.go:626: Server side copy (if possible) Encrypted drive 'TestCryptDrive:rclone-test-dozoqax1kegu' -> Encrypted drive 'TestCryptDrive:rclone-test-yozebuj9yude' 2025/05/04 05:42:55 DEBUG : Added delayed dir = "sub dir", newDst= 2025/05/04 05:42:55 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2025/05/04 05:42:55 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yozebuj9yude': Waiting for checks to finish 2025/05/04 05:42:55 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yozebuj9yude': Waiting for transfers to finish 2025/05/04 05:42:58 INFO : sub dir/hello world: Copied (server-side copy) 2025/05/04 05:42:58 INFO : sub dir: Set directory modification time (using DirSetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dozoqax1kegu'", Local "Local file system at /tmp/rclone3598271736", Modify Window "1ms" 2025/05/04 05:43:00 DEBUG : sub dir/hello world: md5 = 6d3cf384c16df688e0fc9355b8cf04a6 OK 2025/05/04 05:43:01 DEBUG : sub dir: Directory modification time the same (differ by 0s, within tolerance 1ms) 2025/05/04 05:43:01 DEBUG : Added delayed dir = "sub dir", newDst=sub dir 2025/05/04 05:43:01 DEBUG : sub dir/hello world: Sizes differ (src 17 vs dst 11) 2025/05/04 05:43:01 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yozebuj9yude': Waiting for checks to finish 2025/05/04 05:43:01 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yozebuj9yude': Waiting for transfers to finish 2025/05/04 05:43:02 INFO : sub dir/hello world: Copied (server-side copy) 2025/05/04 05:43:02 INFO : sub dir: Set directory modification time (using SetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dozoqax1kegu'", Local "Local file system at /tmp/rclone3598271736", Modify Window "1ms" 2025/05/04 05:43:03 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yozebuj9yude': Purge remote 2025/05/04 05:43:05 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestServerSideCopyOverSelf (14.73s) === RUN TestMoveOverSelf run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dozoqax1kegu'", Local "Local file system at /tmp/rclone3598271736", Modify Window "1ms" 2025/05/04 05:43:08 DEBUG : sub dir/hello world: md5 = e6ff8985cb79d3852349044724906eb9 OK 2025/05/04 05:43:10 INFO : sub dir: Set directory modification time (using SetModTime) 2025/05/04 05:43:10 DEBUG : Added delayed dir = "sub dir", newDst=sub dir 2025/05/04 05:43:10 DEBUG : sub dir/hello world: Sizes differ (src 17 vs dst 11) 2025/05/04 05:43:10 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dozoqax1kegu': Waiting for checks to finish 2025/05/04 05:43:10 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dozoqax1kegu': Waiting for transfers to finish 2025/05/04 05:43:11 DEBUG : sub dir/hello world: md5 = b9dde0b5c33dc9956b7cd7164f149877 OK 2025/05/04 05:43:11 INFO : sub dir/hello world: Copied (replaced existing) 2025/05/04 05:43:11 INFO : sub dir/hello world: Deleted 2025/05/04 05:43:12 INFO : sub dir: Set directory modification time (using SetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dozoqax1kegu'", Local "Local file system at /tmp/rclone3598271736", Modify Window "1ms" 2025/05/04 05:43:14 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestMoveOverSelf (8.54s) === RUN TestServerSideMoveOverSelf run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dozoqax1kegu'", Local "Local file system at /tmp/rclone3598271736", Modify Window "1ms" 2025/05/04 05:43:17 DEBUG : sub dir/hello world: md5 = 977dda08b47a9bb111f0801995c23259 OK 2025/05/04 05:43:17 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-jiraqav6saqu" 2025/05/04 05:43:17 DEBUG : Creating backend with remote "TestDrive:crypt/jgn5ltl5238baoq74pirpeqtfjac3jvoph3633dvgnikrl5jqosg" sync_test.go:671: Server side copy (if possible) Encrypted drive 'TestCryptDrive:rclone-test-dozoqax1kegu' -> Encrypted drive 'TestCryptDrive:rclone-test-jiraqav6saqu' 2025/05/04 05:43:19 DEBUG : Added delayed dir = "sub dir", newDst= 2025/05/04 05:43:19 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2025/05/04 05:43:19 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-jiraqav6saqu': Waiting for checks to finish 2025/05/04 05:43:19 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-jiraqav6saqu': Waiting for transfers to finish 2025/05/04 05:43:21 INFO : sub dir/hello world: Copied (server-side copy) 2025/05/04 05:43:22 INFO : sub dir: Set directory modification time (using DirSetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dozoqax1kegu'", Local "Local file system at /tmp/rclone3598271736", Modify Window "1ms" 2025/05/04 05:43:23 DEBUG : sub dir/hello world: md5 = fa1e113fe3ae317a9cc03c703b680008 OK 2025/05/04 05:43:24 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-jiraqav6saqu': Using server-side directory move 2025/05/04 05:43:24 INFO : Encrypted drive 'TestCryptDrive:rclone-test-jiraqav6saqu': Server side directory move failed - fallback to file moves: can't copy directory - destination already exists 2025/05/04 05:43:24 DEBUG : sub dir: Directory modification time the same (differ by 0s, within tolerance 1ms) 2025/05/04 05:43:24 DEBUG : Added delayed dir = "sub dir", newDst=sub dir 2025/05/04 05:43:24 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-jiraqav6saqu': Waiting for checks to finish 2025/05/04 05:43:24 DEBUG : sub dir/hello world: Sizes differ (src 17 vs dst 11) 2025/05/04 05:43:24 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-jiraqav6saqu': Waiting for transfers to finish 2025/05/04 05:43:25 INFO : sub dir/hello world: Deleted 2025/05/04 05:43:25 INFO : sub dir/hello world: Moved (server-side) 2025/05/04 05:43:26 INFO : sub dir: Set directory modification time (using SetModTime) 2025/05/04 05:43:28 DEBUG : sub dir/hello world: md5 = f619380187b7bb2f51595c4e468acf3f OK 2025/05/04 05:43:28 DEBUG : testing file moves 2025/05/04 05:43:29 DEBUG : sub dir: Directory modification time the same (differ by 0s, within tolerance 1ms) 2025/05/04 05:43:29 DEBUG : Added delayed dir = "sub dir", newDst=sub dir 2025/05/04 05:43:29 DEBUG : sub dir/hello world: Sizes differ (src 24 vs dst 17) 2025/05/04 05:43:29 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-jiraqav6saqu': Waiting for checks to finish 2025/05/04 05:43:29 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-jiraqav6saqu': Waiting for transfers to finish 2025/05/04 05:43:29 INFO : sub dir/hello world: Deleted 2025/05/04 05:43:30 INFO : sub dir/hello world: Moved (server-side) 2025/05/04 05:43:30 INFO : sub dir: Set directory modification time (using SetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dozoqax1kegu'", Local "Local file system at /tmp/rclone3598271736", Modify Window "1ms" 2025/05/04 05:43:31 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-jiraqav6saqu': Purge remote --- PASS: TestServerSideMoveOverSelf (19.12s) === RUN TestCopyAfterDelete run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dozoqax1kegu'", Local "Local file system at /tmp/rclone3598271736", Modify Window "1ms" 2025/05/04 05:43:36 DEBUG : sub dir/hello world: md5 = 8689758213858b6e68f75f28758b77f1 OK 2025/05/04 05:43:36 ERROR : : error listing: directory not found 2025/05/04 05:43:36 INFO : Local file system at /tmp/rclone3598271736: Making directory 2025/05/04 05:43:37 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dozoqax1kegu': Waiting for checks to finish 2025/05/04 05:43:37 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dozoqax1kegu': Waiting for transfers to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dozoqax1kegu'", Local "Local file system at /tmp/rclone3598271736", Modify Window "1ms" 2025/05/04 05:43:38 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestCopyAfterDelete (5.52s) === RUN TestCopyRedownload run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dozoqax1kegu'", Local "Local file system at /tmp/rclone3598271736", Modify Window "1ms" 2025/05/04 05:43:41 DEBUG : sub dir/hello world: md5 = 04e3157417b206f81d8aac17303d7409 OK 2025/05/04 05:43:42 DEBUG : Added delayed dir = "sub dir", newDst= 2025/05/04 05:43:42 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2025/05/04 05:43:42 DEBUG : Local file system at /tmp/rclone3598271736: Waiting for checks to finish 2025/05/04 05:43:42 DEBUG : Local file system at /tmp/rclone3598271736: Waiting for transfers to finish 2025/05/04 05:43:43 DEBUG : sub dir/hello world.285f0a30.partial: renamed to: sub dir/hello world 2025/05/04 05:43:43 INFO : sub dir/hello world: Copied (new) 2025/05/04 05:43:43 INFO : sub dir: Set directory modification time (using DirSetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dozoqax1kegu'", Local "Local file system at /tmp/rclone3598271736", Modify Window "1ms" 2025/05/04 05:43:44 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestCopyRedownload (6.09s) === RUN TestSyncBasedOnCheckSum run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dozoqax1kegu'", Local "Local file system at /tmp/rclone3598271736", Modify Window "1ms" 2025/05/04 05:43:46 DEBUG : check sum: Need to transfer - File not found at Destination 2025/05/04 05:43:46 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dozoqax1kegu': Waiting for checks to finish 2025/05/04 05:43:46 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dozoqax1kegu': Waiting for transfers to finish 2025/05/04 05:43:47 DEBUG : check sum: md5 = 54320496a7d4561a91d1184da1a6f287 OK 2025/05/04 05:43:47 INFO : check sum: Copied (new) 2025/05/04 05:43:47 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dozoqax1kegu'", Local "Local file system at /tmp/rclone3598271736", Modify Window "1ms" 2025/05/04 05:43:47 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dozoqax1kegu': Waiting for checks to finish 2025/05/04 05:43:47 NOTICE: Encrypted drive 'TestCryptDrive:rclone-test-dozoqax1kegu': --checksum is in use but the source and destination have no hashes in common; falling back to --size-only 2025/05/04 05:43:47 DEBUG : check sum: Size of src and dst objects identical 2025/05/04 05:43:47 DEBUG : check sum: Unchanged skipping 2025/05/04 05:43:47 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dozoqax1kegu': Waiting for transfers to finish 2025/05/04 05:43:47 DEBUG : Waiting for deletions to finish 2025/05/04 05:43:47 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dozoqax1kegu'", Local "Local file system at /tmp/rclone3598271736", Modify Window "1ms" --- PASS: TestSyncBasedOnCheckSum (4.07s) === RUN TestSyncSizeOnly run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dozoqax1kegu'", Local "Local file system at /tmp/rclone3598271736", Modify Window "1ms" 2025/05/04 05:43:50 DEBUG : sizeonly: Need to transfer - File not found at Destination 2025/05/04 05:43:50 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dozoqax1kegu': Waiting for checks to finish 2025/05/04 05:43:50 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dozoqax1kegu': Waiting for transfers to finish 2025/05/04 05:43:51 DEBUG : sizeonly: md5 = ef21e57b5a1159f1fe8b4d341e648f39 OK 2025/05/04 05:43:51 INFO : sizeonly: Copied (new) 2025/05/04 05:43:51 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dozoqax1kegu'", Local "Local file system at /tmp/rclone3598271736", Modify Window "1ms" 2025/05/04 05:43:51 DEBUG : sizeonly: Sizes identical 2025/05/04 05:43:51 DEBUG : sizeonly: Unchanged skipping 2025/05/04 05:43:51 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dozoqax1kegu': Waiting for checks to finish 2025/05/04 05:43:51 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dozoqax1kegu': Waiting for transfers to finish 2025/05/04 05:43:51 DEBUG : Waiting for deletions to finish 2025/05/04 05:43:51 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dozoqax1kegu'", Local "Local file system at /tmp/rclone3598271736", Modify Window "1ms" --- PASS: TestSyncSizeOnly (4.10s) === RUN TestSyncIgnoreSize run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dozoqax1kegu'", Local "Local file system at /tmp/rclone3598271736", Modify Window "1ms" 2025/05/04 05:43:54 DEBUG : ignore-size: Need to transfer - File not found at Destination 2025/05/04 05:43:54 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dozoqax1kegu': Waiting for checks to finish 2025/05/04 05:43:54 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dozoqax1kegu': Waiting for transfers to finish 2025/05/04 05:43:55 DEBUG : ignore-size: md5 = 371d8929bb8e5ceec9963c0d7671f537 OK 2025/05/04 05:43:55 INFO : ignore-size: Copied (new) 2025/05/04 05:43:55 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dozoqax1kegu'", Local "Local file system at /tmp/rclone3598271736", Modify Window "1ms" 2025/05/04 05:43:55 DEBUG : ignore-size: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/05/04 05:43:55 DEBUG : ignore-size: Unchanged skipping 2025/05/04 05:43:55 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dozoqax1kegu': Waiting for checks to finish 2025/05/04 05:43:55 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dozoqax1kegu': Waiting for transfers to finish 2025/05/04 05:43:55 DEBUG : Waiting for deletions to finish 2025/05/04 05:43:55 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dozoqax1kegu'", Local "Local file system at /tmp/rclone3598271736", Modify Window "1ms" --- PASS: TestSyncIgnoreSize (4.05s) === RUN TestSyncIgnoreTimes run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dozoqax1kegu'", Local "Local file system at /tmp/rclone3598271736", Modify Window "1ms" 2025/05/04 05:43:59 DEBUG : existing: md5 = 3c5b891eb6557e5017952f42e3507e40 OK 2025/05/04 05:43:59 DEBUG : existing: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/05/04 05:43:59 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dozoqax1kegu': Waiting for checks to finish 2025/05/04 05:43:59 DEBUG : existing: Unchanged skipping 2025/05/04 05:43:59 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dozoqax1kegu': Waiting for transfers to finish 2025/05/04 05:43:59 DEBUG : Waiting for deletions to finish 2025/05/04 05:43:59 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dozoqax1kegu'", Local "Local file system at /tmp/rclone3598271736", Modify Window "1ms" 2025/05/04 05:43:59 DEBUG : existing: Transferring unconditionally as --ignore-times is in use 2025/05/04 05:43:59 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dozoqax1kegu': Waiting for checks to finish 2025/05/04 05:43:59 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dozoqax1kegu': Waiting for transfers to finish 2025/05/04 05:44:00 DEBUG : existing: md5 = 69ddc42f4943588df3853d69029cd0c2 OK 2025/05/04 05:44:00 INFO : existing: Copied (replaced existing) 2025/05/04 05:44:00 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dozoqax1kegu'", Local "Local file system at /tmp/rclone3598271736", Modify Window "1ms" --- PASS: TestSyncIgnoreTimes (4.91s) === RUN TestSyncIgnoreExisting run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dozoqax1kegu'", Local "Local file system at /tmp/rclone3598271736", Modify Window "1ms" 2025/05/04 05:44:03 DEBUG : existing: Need to transfer - File not found at Destination 2025/05/04 05:44:03 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dozoqax1kegu': Waiting for checks to finish 2025/05/04 05:44:03 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dozoqax1kegu': Waiting for transfers to finish 2025/05/04 05:44:04 DEBUG : existing: md5 = 539f56ce51e7a1b4d22b2cf77a92e3e2 OK 2025/05/04 05:44:04 INFO : existing: Copied (new) 2025/05/04 05:44:04 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dozoqax1kegu'", Local "Local file system at /tmp/rclone3598271736", Modify Window "1ms" 2025/05/04 05:44:04 DEBUG : existing: Destination exists, skipping 2025/05/04 05:44:04 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dozoqax1kegu': Waiting for checks to finish 2025/05/04 05:44:04 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dozoqax1kegu': Waiting for transfers to finish 2025/05/04 05:44:04 DEBUG : Waiting for deletions to finish 2025/05/04 05:44:04 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dozoqax1kegu'", Local "Local file system at /tmp/rclone3598271736", Modify Window "1ms" --- PASS: TestSyncIgnoreExisting (4.10s) === RUN TestSyncIgnoreErrors run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dozoqax1kegu'", Local "Local file system at /tmp/rclone3598271736", Modify Window "1ms" 2025/05/04 05:44:09 DEBUG : b/potato: md5 = aab39b1954dfcd42d0dd2b8f15dcaa8d OK 2025/05/04 05:44:11 DEBUG : c/non empty space: md5 = a3bc36f0dbb03dd3530891bbd8cc949c OK 2025/05/04 05:44:11 INFO : d: Making directory 2025/05/04 05:44:12 DEBUG : Added delayed dir = "a", newDst= 2025/05/04 05:44:13 INFO : c: Set directory modification time (using SetModTime) 2025/05/04 05:44:13 DEBUG : Added delayed dir = "c", newDst=c 2025/05/04 05:44:13 DEBUG : c/non empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/05/04 05:44:13 DEBUG : a/potato2: Need to transfer - File not found at Destination 2025/05/04 05:44:13 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dozoqax1kegu': Waiting for checks to finish 2025/05/04 05:44:13 DEBUG : c/non empty space: Unchanged skipping 2025/05/04 05:44:13 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dozoqax1kegu': Waiting for transfers to finish 2025/05/04 05:44:15 DEBUG : a/potato2: md5 = f8d0ad6a80d8c60df8a11c1052482e21 OK 2025/05/04 05:44:15 INFO : a/potato2: Copied (new) 2025/05/04 05:44:15 DEBUG : Waiting for deletions to finish 2025/05/04 05:44:15 INFO : b/potato: Deleted 2025/05/04 05:44:16 INFO : a: Set directory modification time (using DirSetModTime) 2025/05/04 05:44:16 INFO : d: Removing directory 2025/05/04 05:44:16 INFO : b: Removing directory 2025/05/04 05:44:17 DEBUG : 32d8ua6196mc1r7qkfog53rkg0: Rmdir: contains trashed file: "2m507n64kafsi59v9q71r281a4" 2025/05/04 05:44:17 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dozoqax1kegu': deleted 2 directories run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dozoqax1kegu'", Local "Local file system at /tmp/rclone3598271736", Modify Window "1ms" 2025/05/04 05:44:19 DEBUG : 3i9du405pfogq3ncai6pg7ouio: Rmdir: contains trashed file: "982d3pss7t5pn0il16r2foj31s" 2025/05/04 05:44:20 DEBUG : 2bsvlrk2ne1lfitm6tttcu0qt8: Rmdir: contains trashed file: "89l8renevh3mji1c8r1p7qn6tg" --- PASS: TestSyncIgnoreErrors (14.42s) === RUN TestSyncAfterChangingModtimeOnly run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dozoqax1kegu'", Local "Local file system at /tmp/rclone3598271736", Modify Window "1ms" 2025/05/04 05:44:22 DEBUG : empty space: md5 = 2e70b4e44f5df6dcc767e4cf613ca878 OK 2025/05/04 05:44:23 DEBUG : empty space: Modification times differ by -95456h54m52.624456789s: 2011-12-25 12:59:59.123456789 +0000 UTC, 2001-02-03 04:05:06.499 +0000 UTC 2025/05/04 05:44:23 NOTICE: empty space: Skipped copy as --dry-run is set (size 1) 2025/05/04 05:44:23 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dozoqax1kegu': Waiting for checks to finish 2025/05/04 05:44:23 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dozoqax1kegu': Waiting for transfers to finish 2025/05/04 05:44:23 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dozoqax1kegu'", Local "Local file system at /tmp/rclone3598271736", Modify Window "1ms" 2025/05/04 05:44:23 DEBUG : empty space: Modification times differ by -95456h54m52.624456789s: 2011-12-25 12:59:59.123456789 +0000 UTC, 2001-02-03 04:05:06.499 +0000 UTC 2025/05/04 05:44:23 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dozoqax1kegu': Waiting for checks to finish 2025/05/04 05:44:23 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dozoqax1kegu': Waiting for transfers to finish 2025/05/04 05:44:24 DEBUG : empty space: md5 = a93810cfccea0a4b6f5e6aeb70663a39 OK 2025/05/04 05:44:24 INFO : empty space: Copied (replaced existing) 2025/05/04 05:44:24 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dozoqax1kegu'", Local "Local file system at /tmp/rclone3598271736", Modify Window "1ms" --- PASS: TestSyncAfterChangingModtimeOnly (5.01s) === RUN TestSyncAfterChangingModtimeOnlyWithNoUpdateModTime run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dozoqax1kegu'", Local "Local file system at /tmp/rclone3598271736", Modify Window "1ms" sync_test.go:1016: Can't check this if no hashes supported --- PASS: TestSyncAfterChangingModtimeOnlyWithNoUpdateModTime (0.41s) === RUN TestSyncDoesntUpdateModtime run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dozoqax1kegu'", Local "Local file system at /tmp/rclone3598271736", Modify Window "1ms" 2025/05/04 05:44:28 DEBUG : foo: md5 = 6fdb2a6d80561bd5e93552019fc2f0c1 OK 2025/05/04 05:44:28 DEBUG : foo: Modification times differ by -95456h54m52.624456789s: 2011-12-25 12:59:59.123456789 +0000 UTC, 2001-02-03 04:05:06.499 +0000 UTC 2025/05/04 05:44:28 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dozoqax1kegu': Waiting for checks to finish 2025/05/04 05:44:28 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dozoqax1kegu': Waiting for transfers to finish 2025/05/04 05:44:30 DEBUG : foo: md5 = b9dfe44ba4f14f998d1eff37d4432ebd OK 2025/05/04 05:44:30 INFO : foo: Copied (replaced existing) 2025/05/04 05:44:30 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dozoqax1kegu'", Local "Local file system at /tmp/rclone3598271736", Modify Window "1ms" --- PASS: TestSyncDoesntUpdateModtime (4.67s) === RUN TestSyncAfterAddingAFile run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dozoqax1kegu'", Local "Local file system at /tmp/rclone3598271736", Modify Window "1ms" 2025/05/04 05:44:32 DEBUG : empty space: md5 = a80adf645af1b052d7331e799d395d2e OK 2025/05/04 05:44:33 DEBUG : empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/05/04 05:44:33 DEBUG : potato: Need to transfer - File not found at Destination 2025/05/04 05:44:33 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dozoqax1kegu': Waiting for checks to finish 2025/05/04 05:44:33 DEBUG : empty space: Unchanged skipping 2025/05/04 05:44:33 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dozoqax1kegu': Waiting for transfers to finish 2025/05/04 05:44:34 DEBUG : potato: md5 = d4ae305b5fe8034998366d9cbbf6f4b9 OK 2025/05/04 05:44:34 INFO : potato: Copied (new) 2025/05/04 05:44:34 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dozoqax1kegu'", Local "Local file system at /tmp/rclone3598271736", Modify Window "1ms" --- PASS: TestSyncAfterAddingAFile (4.84s) === RUN TestSyncAfterChangingFilesSizeOnly run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dozoqax1kegu'", Local "Local file system at /tmp/rclone3598271736", Modify Window "1ms" 2025/05/04 05:44:37 DEBUG : potato: md5 = 4ac4452e3e92cf90d3fcf2593fa0eb0e OK 2025/05/04 05:44:38 DEBUG : potato: Sizes differ (src 21 vs dst 60) 2025/05/04 05:44:38 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dozoqax1kegu': Waiting for checks to finish 2025/05/04 05:44:38 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dozoqax1kegu': Waiting for transfers to finish 2025/05/04 05:44:39 DEBUG : potato: md5 = 7611de93c846ff9dde4dd2a0249bc827 OK 2025/05/04 05:44:39 INFO : potato: Copied (replaced existing) 2025/05/04 05:44:39 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dozoqax1kegu'", Local "Local file system at /tmp/rclone3598271736", Modify Window "1ms" --- PASS: TestSyncAfterChangingFilesSizeOnly (4.34s) === RUN TestSyncAfterChangingContentsOnly run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dozoqax1kegu'", Local "Local file system at /tmp/rclone3598271736", Modify Window "1ms" 2025/05/04 05:44:41 DEBUG : potato: md5 = 3b147a99a297326e4ad8cc14e49129fa OK 2025/05/04 05:44:42 DEBUG : potato: Modification times differ by 119h59m59.876543211s: 2011-12-25 12:59:59.123456789 +0000 UTC, 2011-12-30 12:59:59 +0000 UTC 2025/05/04 05:44:42 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dozoqax1kegu': Waiting for checks to finish 2025/05/04 05:44:42 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dozoqax1kegu': Waiting for transfers to finish 2025/05/04 05:44:43 DEBUG : potato: md5 = 7282ea1a2297aa00bf8c5673600ae861 OK 2025/05/04 05:44:43 INFO : potato: Copied (replaced existing) 2025/05/04 05:44:43 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dozoqax1kegu'", Local "Local file system at /tmp/rclone3598271736", Modify Window "1ms" --- PASS: TestSyncAfterChangingContentsOnly (4.45s) === RUN TestSyncAfterRemovingAFileAndAddingAFileDryRun run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dozoqax1kegu'", Local "Local file system at /tmp/rclone3598271736", Modify Window "1ms" 2025/05/04 05:44:46 DEBUG : potato: md5 = 605137a6f320ab0eea89c8733100fd6d OK 2025/05/04 05:44:47 DEBUG : empty space: md5 = 0eda581609d676b545260f42b4476594 OK 2025/05/04 05:44:48 DEBUG : potato2: Need to transfer - File not found at Destination 2025/05/04 05:44:48 DEBUG : empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/05/04 05:44:48 DEBUG : empty space: Unchanged skipping 2025/05/04 05:44:48 NOTICE: potato2: Skipped copy as --dry-run is set (size 60) 2025/05/04 05:44:48 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dozoqax1kegu': Waiting for checks to finish 2025/05/04 05:44:48 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dozoqax1kegu': Waiting for transfers to finish 2025/05/04 05:44:48 DEBUG : Waiting for deletions to finish 2025/05/04 05:44:48 NOTICE: potato: Skipped delete as --dry-run is set (size 21) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dozoqax1kegu'", Local "Local file system at /tmp/rclone3598271736", Modify Window "1ms" --- PASS: TestSyncAfterRemovingAFileAndAddingAFileDryRun (4.88s) === RUN TestSyncAfterRemovingAFileAndAddingAFile run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dozoqax1kegu'", Local "Local file system at /tmp/rclone3598271736", Modify Window "1ms" 2025/05/04 05:44:51 DEBUG : potato: md5 = ce2a50a39c714ea76650812536d2d57a OK 2025/05/04 05:44:52 DEBUG : empty space: md5 = 1ec80f0a4bbba4a6b4ddc964505abef9 OK 2025/05/04 05:44:53 DEBUG : empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/05/04 05:44:53 DEBUG : potato2: Need to transfer - File not found at Destination 2025/05/04 05:44:53 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dozoqax1kegu': Waiting for checks to finish 2025/05/04 05:44:53 DEBUG : empty space: Unchanged skipping 2025/05/04 05:44:53 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dozoqax1kegu': Waiting for transfers to finish 2025/05/04 05:44:54 DEBUG : potato2: md5 = 4f2ee19b9d10146c3d56382ace0dd217 OK 2025/05/04 05:44:54 INFO : potato2: Copied (new) 2025/05/04 05:44:54 DEBUG : Waiting for deletions to finish 2025/05/04 05:44:55 INFO : potato: Deleted run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dozoqax1kegu'", Local "Local file system at /tmp/rclone3598271736", Modify Window "1ms" --- PASS: TestSyncAfterRemovingAFileAndAddingAFile (7.15s) === RUN TestSyncAfterRemovingAFileAndAddingAFileSubDir run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dozoqax1kegu'", Local "Local file system at /tmp/rclone3598271736", Modify Window "1ms" 2025/05/04 05:44:59 DEBUG : b/potato: md5 = d96b0bd22d8d3249bdec737a14e0bdc7 OK 2025/05/04 05:45:01 DEBUG : c/non empty space: md5 = ae0b42df04528d98b917d541601906d9 OK 2025/05/04 05:45:01 INFO : d: Making directory 2025/05/04 05:45:02 INFO : d/e: Making directory 2025/05/04 05:45:04 DEBUG : Added delayed dir = "a", newDst= 2025/05/04 05:45:04 INFO : c: Set directory modification time (using SetModTime) 2025/05/04 05:45:04 DEBUG : Added delayed dir = "c", newDst=c 2025/05/04 05:45:04 DEBUG : c/non empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/05/04 05:45:04 DEBUG : c/non empty space: Unchanged skipping 2025/05/04 05:45:04 DEBUG : a/potato2: Need to transfer - File not found at Destination 2025/05/04 05:45:04 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dozoqax1kegu': Waiting for checks to finish 2025/05/04 05:45:04 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dozoqax1kegu': Waiting for transfers to finish 2025/05/04 05:45:06 DEBUG : a/potato2: md5 = 38190abb30f854b4b012e06ecb3dccb2 OK 2025/05/04 05:45:06 INFO : a/potato2: Copied (new) 2025/05/04 05:45:06 DEBUG : Waiting for deletions to finish 2025/05/04 05:45:07 INFO : b/potato: Deleted 2025/05/04 05:45:07 INFO : a: Set directory modification time (using DirSetModTime) 2025/05/04 05:45:07 INFO : d/e: Removing directory 2025/05/04 05:45:08 INFO : d: Removing directory 2025/05/04 05:45:08 DEBUG : ka6id8d20d3s5ktapedlphgta8: Rmdir: contains trashed file: "r8sppajuabeak3sbgj2ak8vuf8" 2025/05/04 05:45:09 INFO : b: Removing directory 2025/05/04 05:45:09 DEBUG : 32d8ua6196mc1r7qkfog53rkg0: Rmdir: contains trashed file: "2m507n64kafsi59v9q71r281a4" 2025/05/04 05:45:09 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dozoqax1kegu': deleted 3 directories run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dozoqax1kegu'", Local "Local file system at /tmp/rclone3598271736", Modify Window "1ms" 2025/05/04 05:45:11 DEBUG : 3i9du405pfogq3ncai6pg7ouio: Rmdir: contains trashed file: "982d3pss7t5pn0il16r2foj31s" 2025/05/04 05:45:12 DEBUG : 2bsvlrk2ne1lfitm6tttcu0qt8: Rmdir: contains trashed file: "89l8renevh3mji1c8r1p7qn6tg" --- PASS: TestSyncAfterRemovingAFileAndAddingAFileSubDir (16.29s) === RUN TestSyncAfterRemovingAFileAndAddingAFileSubDirWithErrors run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dozoqax1kegu'", Local "Local file system at /tmp/rclone3598271736", Modify Window "1ms" 2025/05/04 05:45:15 DEBUG : b/potato: md5 = 4ed1740a78c8c392a748618c9cb4dd6b OK 2025/05/04 05:45:17 DEBUG : c/non empty space: md5 = d33c97f574da3a68e428cd9c200d74d9 OK 2025/05/04 05:45:17 INFO : d: Making directory 2025/05/04 05:45:19 DEBUG : Added delayed dir = "a", newDst= 2025/05/04 05:45:19 INFO : c: Set directory modification time (using SetModTime) 2025/05/04 05:45:19 DEBUG : Added delayed dir = "c", newDst=c 2025/05/04 05:45:19 DEBUG : c/non empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/05/04 05:45:19 DEBUG : a/potato2: Need to transfer - File not found at Destination 2025/05/04 05:45:19 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dozoqax1kegu': Waiting for checks to finish 2025/05/04 05:45:19 DEBUG : c/non empty space: Unchanged skipping 2025/05/04 05:45:19 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dozoqax1kegu': Waiting for transfers to finish 2025/05/04 05:45:21 DEBUG : a/potato2: md5 = a82df747c26b928326885b3b8d0540ea OK 2025/05/04 05:45:21 INFO : a/potato2: Copied (new) 2025/05/04 05:45:21 ERROR : Encrypted drive 'TestCryptDrive:rclone-test-dozoqax1kegu': not deleting files as there were IO errors 2025/05/04 05:45:22 INFO : a: Set directory modification time (using DirSetModTime) 2025/05/04 05:45:22 ERROR : Encrypted drive 'TestCryptDrive:rclone-test-dozoqax1kegu': not deleting directories as there were IO errors run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dozoqax1kegu'", Local "Local file system at /tmp/rclone3598271736", Modify Window "1ms" 2025/05/04 05:45:25 DEBUG : 3i9du405pfogq3ncai6pg7ouio: Rmdir: contains trashed file: "982d3pss7t5pn0il16r2foj31s" 2025/05/04 05:45:26 DEBUG : 32d8ua6196mc1r7qkfog53rkg0: Rmdir: contains trashed file: "2m507n64kafsi59v9q71r281a4" 2025/05/04 05:45:26 DEBUG : 2bsvlrk2ne1lfitm6tttcu0qt8: Rmdir: contains trashed file: "89l8renevh3mji1c8r1p7qn6tg" --- PASS: TestSyncAfterRemovingAFileAndAddingAFileSubDirWithErrors (14.63s) === RUN TestSyncDeleteAfter --- PASS: TestSyncDeleteAfter (0.00s) === RUN TestSyncDeleteDuring run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dozoqax1kegu'", Local "Local file system at /tmp/rclone3598271736", Modify Window "1ms" 2025/05/04 05:45:29 DEBUG : potato: md5 = 6f4320eb8f66929d0ceed342f62f4c5c OK 2025/05/04 05:45:30 DEBUG : empty space: md5 = 8e0c038b426ace6b104324563f190ff6 OK 2025/05/04 05:45:30 DEBUG : Waiting for deletions to finish 2025/05/04 05:45:31 DEBUG : empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/05/04 05:45:31 DEBUG : potato2: Need to transfer - File not found at Destination 2025/05/04 05:45:31 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dozoqax1kegu': Waiting for checks to finish 2025/05/04 05:45:31 DEBUG : empty space: Unchanged skipping 2025/05/04 05:45:31 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dozoqax1kegu': Waiting for transfers to finish 2025/05/04 05:45:31 INFO : potato: Deleted 2025/05/04 05:45:32 DEBUG : potato2: md5 = 02d60fd4ed755f45e941800e7e554062 OK 2025/05/04 05:45:32 INFO : potato2: Copied (new) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dozoqax1kegu'", Local "Local file system at /tmp/rclone3598271736", Modify Window "1ms" --- PASS: TestSyncDeleteDuring (6.55s) === RUN TestSyncDeleteBefore run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dozoqax1kegu'", Local "Local file system at /tmp/rclone3598271736", Modify Window "1ms" 2025/05/04 05:45:35 DEBUG : potato: md5 = b30608577ba65b17a7f64e3c27473d0a OK 2025/05/04 05:45:37 DEBUG : empty space: md5 = 4a9f20253bd1c356d68d36bf5beaac78 OK 2025/05/04 05:45:37 DEBUG : Waiting for deletions to finish 2025/05/04 05:45:37 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dozoqax1kegu': Waiting for checks to finish 2025/05/04 05:45:37 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dozoqax1kegu': Waiting for transfers to finish 2025/05/04 05:45:38 INFO : potato: Deleted 2025/05/04 05:45:38 DEBUG : empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/05/04 05:45:38 DEBUG : potato2: Need to transfer - File not found at Destination 2025/05/04 05:45:38 DEBUG : empty space: Unchanged skipping 2025/05/04 05:45:38 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dozoqax1kegu': Waiting for checks to finish 2025/05/04 05:45:38 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dozoqax1kegu': Waiting for transfers to finish 2025/05/04 05:45:39 DEBUG : potato2: md5 = 1019dc6cfcf4f8ee8d5c039047430024 OK 2025/05/04 05:45:39 INFO : potato2: Copied (new) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dozoqax1kegu'", Local "Local file system at /tmp/rclone3598271736", Modify Window "1ms" --- PASS: TestSyncDeleteBefore (7.06s) === RUN TestCopyDeleteBefore run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dozoqax1kegu'", Local "Local file system at /tmp/rclone3598271736", Modify Window "1ms" 2025/05/04 05:45:43 DEBUG : potato: md5 = 6874ecb6fe55b1b7c2c5ff9b7fc5384c OK 2025/05/04 05:45:43 DEBUG : potato2: Need to transfer - File not found at Destination 2025/05/04 05:45:43 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dozoqax1kegu': Waiting for checks to finish 2025/05/04 05:45:43 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dozoqax1kegu': Waiting for transfers to finish 2025/05/04 05:45:44 DEBUG : potato2: md5 = 5cb2b0ed818f21d023911011f38a3374 OK 2025/05/04 05:45:44 INFO : potato2: Copied (new) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dozoqax1kegu'", Local "Local file system at /tmp/rclone3598271736", Modify Window "1ms" --- PASS: TestCopyDeleteBefore (5.17s) === RUN TestSyncWithExclude run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dozoqax1kegu'", Local "Local file system at /tmp/rclone3598271736", Modify Window "1ms" 2025/05/04 05:45:48 DEBUG : potato2: md5 = 5bac74cfefaa082d21a15f07227a43e4 OK 2025/05/04 05:45:49 DEBUG : empty space: md5 = d026d412ad2ead3beefe2daff7b355b3 OK 2025/05/04 05:45:49 DEBUG : enormous: Excluded (Size Filter) 2025/05/04 05:45:49 DEBUG : enormous: Excluded 2025/05/04 05:45:49 DEBUG : potato2: Excluded (Size Filter) 2025/05/04 05:45:49 DEBUG : potato2: Excluded 2025/05/04 05:45:49 DEBUG : potato2: Excluded (Size Filter) 2025/05/04 05:45:49 DEBUG : empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/05/04 05:45:49 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dozoqax1kegu': Waiting for checks to finish 2025/05/04 05:45:49 DEBUG : empty space: Unchanged skipping 2025/05/04 05:45:49 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dozoqax1kegu': Waiting for transfers to finish 2025/05/04 05:45:49 DEBUG : Waiting for deletions to finish 2025/05/04 05:45:49 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dozoqax1kegu'", Local "Local file system at /tmp/rclone3598271736", Modify Window "1ms" 2025/05/04 05:45:50 DEBUG : enormous: Excluded (Size Filter) 2025/05/04 05:45:50 DEBUG : enormous: Excluded 2025/05/04 05:45:50 DEBUG : potato2: Excluded (Size Filter) 2025/05/04 05:45:50 DEBUG : potato2: Excluded 2025/05/04 05:45:50 DEBUG : potato2: Excluded (Size Filter) 2025/05/04 05:45:50 DEBUG : empty space: Size and modification time the same (differ by 456.789µs, within tolerance 1ms) 2025/05/04 05:45:50 DEBUG : empty space: Unchanged skipping 2025/05/04 05:45:50 DEBUG : Local file system at /tmp/rclone3598271736: Waiting for checks to finish 2025/05/04 05:45:50 DEBUG : Local file system at /tmp/rclone3598271736: Waiting for transfers to finish 2025/05/04 05:45:50 DEBUG : Waiting for deletions to finish 2025/05/04 05:45:50 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dozoqax1kegu'", Local "Local file system at /tmp/rclone3598271736", Modify Window "1ms" --- PASS: TestSyncWithExclude (5.81s) === RUN TestSyncWithExcludeAndDeleteExcluded run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dozoqax1kegu'", Local "Local file system at /tmp/rclone3598271736", Modify Window "1ms" 2025/05/04 05:45:54 DEBUG : potato2: md5 = f4ac0cef0f9a61a611cb2be9259b23b4 OK 2025/05/04 05:45:55 DEBUG : empty space: md5 = b5848b486b8a56f1b8d2177c4078c27d OK 2025/05/04 05:45:56 DEBUG : enormous: md5 = d3ad777ceb194fa8caf0f85814e5309a OK 2025/05/04 05:45:57 DEBUG : enormous: Excluded (Size Filter) 2025/05/04 05:45:57 DEBUG : enormous: Excluded 2025/05/04 05:45:57 DEBUG : potato2: Excluded (Size Filter) 2025/05/04 05:45:57 DEBUG : potato2: Excluded 2025/05/04 05:45:57 DEBUG : empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/05/04 05:45:57 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dozoqax1kegu': Waiting for checks to finish 2025/05/04 05:45:57 DEBUG : empty space: Unchanged skipping 2025/05/04 05:45:57 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dozoqax1kegu': Waiting for transfers to finish 2025/05/04 05:45:57 DEBUG : Waiting for deletions to finish 2025/05/04 05:45:57 INFO : enormous: Deleted 2025/05/04 05:45:57 INFO : potato2: Deleted 2025/05/04 05:45:57 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dozoqax1kegu'", Local "Local file system at /tmp/rclone3598271736", Modify Window "1ms" 2025/05/04 05:45:58 DEBUG : Local file system at /tmp/rclone3598271736: Waiting for checks to finish 2025/05/04 05:45:58 DEBUG : empty space: Size and modification time the same (differ by 456.789µs, within tolerance 1ms) 2025/05/04 05:45:58 DEBUG : empty space: Unchanged skipping 2025/05/04 05:45:58 DEBUG : Local file system at /tmp/rclone3598271736: Waiting for transfers to finish 2025/05/04 05:45:58 DEBUG : Waiting for deletions to finish 2025/05/04 05:45:58 INFO : potato2: Deleted 2025/05/04 05:45:58 INFO : enormous: Deleted 2025/05/04 05:45:58 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dozoqax1kegu'", Local "Local file system at /tmp/rclone3598271736", Modify Window "1ms" --- PASS: TestSyncWithExcludeAndDeleteExcluded (7.36s) === RUN TestSyncWithUpdateOlder run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dozoqax1kegu'", Local "Local file system at /tmp/rclone3598271736", Modify Window "1ms" 2025/05/04 05:46:01 DEBUG : one: md5 = 6f8ce86f6f02fea01406ac5bd3dcdbd0 OK 2025/05/04 05:46:02 DEBUG : two: md5 = 55434aebd483ffdc6fda8811e634c2b0 OK 2025/05/04 05:46:04 DEBUG : three: md5 = 52c6fb1601d76790f89128685afe9361 OK 2025/05/04 05:46:05 DEBUG : four: md5 = 78eb18e0750744af323340e6934f6c49 OK 2025/05/04 05:46:05 DEBUG : five: Need to transfer - File not found at Destination 2025/05/04 05:46:05 DEBUG : four: Sizes differ (src 4 vs dst 8) 2025/05/04 05:46:05 DEBUG : one: Destination is newer than source, skipping 2025/05/04 05:46:05 DEBUG : three: Sizes identical 2025/05/04 05:46:05 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dozoqax1kegu': Waiting for checks to finish 2025/05/04 05:46:05 DEBUG : four: Destination mod time is within 1s of source but files differ, transferring 2025/05/04 05:46:05 DEBUG : three: Destination mod time is within 1s of source and files identical, skipping 2025/05/04 05:46:05 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dozoqax1kegu': Waiting for transfers to finish 2025/05/04 05:46:06 DEBUG : four: md5 = 5d0d8eb692f1687e9a9106f64ac66410 OK 2025/05/04 05:46:06 INFO : four: Copied (replaced existing) 2025/05/04 05:46:06 DEBUG : two: md5 = 61dc3894ca171289ee3ae9292b5ebf1b OK 2025/05/04 05:46:06 INFO : two: Copied (replaced existing) 2025/05/04 05:46:06 DEBUG : five: md5 = 3ed8efe75c413887fca8afafb0bb39da OK 2025/05/04 05:46:06 INFO : five: Copied (new) 2025/05/04 05:46:06 DEBUG : Waiting for deletions to finish sync_test.go:1449: Skip test with --checksum as no hashes supported --- PASS: TestSyncWithUpdateOlder (9.98s) === 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-dozoqax1kegu'", Local "Local file system at /tmp/rclone3598271736", Modify Window "1ms" sync_test.go:1538: Can track renames: false 2025/05/04 05:46:10 ERROR : Encrypted drive 'TestCryptDrive:rclone-test-dozoqax1kegu': Ignoring --track-renames as the source and destination do not have a common hash 2025/05/04 05:46:10 DEBUG : potato: Need to transfer - File not found at Destination 2025/05/04 05:46:10 DEBUG : yam: Need to transfer - File not found at Destination 2025/05/04 05:46:10 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dozoqax1kegu': Waiting for checks to finish 2025/05/04 05:46:10 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dozoqax1kegu': Waiting for transfers to finish 2025/05/04 05:46:11 DEBUG : yam: md5 = a2864fc0b8df46ca429a1e22104f00b9 OK 2025/05/04 05:46:11 INFO : yam: Copied (new) 2025/05/04 05:46:11 DEBUG : potato: md5 = 641c41aa929d4b24a0d3e1ba132cac49 OK 2025/05/04 05:46:11 INFO : potato: Copied (new) 2025/05/04 05:46:11 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dozoqax1kegu'", Local "Local file system at /tmp/rclone3598271736", Modify Window "1ms" 2025/05/04 05:46:11 ERROR : Encrypted drive 'TestCryptDrive:rclone-test-dozoqax1kegu': Ignoring --track-renames as the source and destination do not have a common hash 2025/05/04 05:46:11 DEBUG : potato: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/05/04 05:46:11 DEBUG : yaml: Need to transfer - File not found at Destination 2025/05/04 05:46:11 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dozoqax1kegu': Waiting for checks to finish 2025/05/04 05:46:11 DEBUG : potato: Unchanged skipping 2025/05/04 05:46:11 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dozoqax1kegu': Waiting for transfers to finish 2025/05/04 05:46:13 DEBUG : yaml: md5 = 146651cb887528f3a16c09848b024ab9 OK 2025/05/04 05:46:13 INFO : yaml: Copied (new) 2025/05/04 05:46:13 DEBUG : Waiting for deletions to finish 2025/05/04 05:46:13 INFO : yam: Deleted run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dozoqax1kegu'", Local "Local file system at /tmp/rclone3598271736", Modify Window "1ms" --- PASS: TestSyncWithTrackRenames (6.43s) === RUN TestParseRenamesStrategyModtime --- PASS: TestParseRenamesStrategyModtime (0.00s) === RUN TestRenamesStrategyModtime --- PASS: TestRenamesStrategyModtime (0.00s) === RUN TestSyncWithTrackRenamesStrategyModtime run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dozoqax1kegu'", Local "Local file system at /tmp/rclone3598271736", Modify Window "1ms" sync_test.go:1610: Can track renames: true 2025/05/04 05:46:16 INFO : Encrypted drive 'TestCryptDrive:rclone-test-dozoqax1kegu': Making map for --track-renames 2025/05/04 05:46:16 INFO : Encrypted drive 'TestCryptDrive:rclone-test-dozoqax1kegu': Finished making map for --track-renames 2025/05/04 05:46:16 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dozoqax1kegu': Waiting for checks to finish 2025/05/04 05:46:16 DEBUG : potato: Need to transfer - No matching file found at Destination 2025/05/04 05:46:16 DEBUG : yam: Need to transfer - No matching file found at Destination 2025/05/04 05:46:16 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dozoqax1kegu': Waiting for renames to finish 2025/05/04 05:46:16 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dozoqax1kegu': Waiting for transfers to finish 2025/05/04 05:46:17 DEBUG : potato: md5 = 3ff529975338f49f6968e858cc00e543 OK 2025/05/04 05:46:17 INFO : potato: Copied (new) 2025/05/04 05:46:17 DEBUG : yam: md5 = 3f2d026dfa8139266784400bc00901a0 OK 2025/05/04 05:46:17 INFO : yam: Copied (new) 2025/05/04 05:46:17 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dozoqax1kegu'", Local "Local file system at /tmp/rclone3598271736", Modify Window "1ms" 2025/05/04 05:46:18 DEBUG : potato: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/05/04 05:46:18 INFO : Encrypted drive 'TestCryptDrive:rclone-test-dozoqax1kegu': Making map for --track-renames 2025/05/04 05:46:18 INFO : Encrypted drive 'TestCryptDrive:rclone-test-dozoqax1kegu': Finished making map for --track-renames 2025/05/04 05:46:18 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dozoqax1kegu': Waiting for checks to finish 2025/05/04 05:46:18 DEBUG : potato: Unchanged skipping 2025/05/04 05:46:18 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dozoqax1kegu': Waiting for renames to finish 2025/05/04 05:46:19 INFO : yam: Moved (server-side) to: yaml 2025/05/04 05:46:19 INFO : yaml: Renamed from "yam" 2025/05/04 05:46:19 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dozoqax1kegu': Waiting for transfers to finish 2025/05/04 05:46:19 DEBUG : Waiting for deletions to finish 2025/05/04 05:46:19 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dozoqax1kegu'", Local "Local file system at /tmp/rclone3598271736", Modify Window "1ms" --- PASS: TestSyncWithTrackRenamesStrategyModtime (5.02s) === RUN TestSyncWithTrackRenamesStrategyLeaf run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dozoqax1kegu'", Local "Local file system at /tmp/rclone3598271736", Modify Window "1ms" sync_test.go:1649: Can track renames: true 2025/05/04 05:46:21 DEBUG : Added delayed dir = "sub", newDst= 2025/05/04 05:46:21 INFO : Encrypted drive 'TestCryptDrive:rclone-test-dozoqax1kegu': Making map for --track-renames 2025/05/04 05:46:21 INFO : Encrypted drive 'TestCryptDrive:rclone-test-dozoqax1kegu': Finished making map for --track-renames 2025/05/04 05:46:21 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dozoqax1kegu': Waiting for checks to finish 2025/05/04 05:46:21 DEBUG : potato: Need to transfer - No matching file found at Destination 2025/05/04 05:46:21 DEBUG : sub/yam: Need to transfer - No matching file found at Destination 2025/05/04 05:46:21 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dozoqax1kegu': Waiting for renames to finish 2025/05/04 05:46:21 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dozoqax1kegu': Waiting for transfers to finish 2025/05/04 05:46:23 DEBUG : potato: md5 = ed0bf8384f2a711ff8a44219eb395dac OK 2025/05/04 05:46:23 INFO : potato: Copied (new) 2025/05/04 05:46:23 DEBUG : sub/yam: md5 = e406ca9154a106f49b998c3a699787da OK 2025/05/04 05:46:23 INFO : sub/yam: Copied (new) 2025/05/04 05:46:23 DEBUG : Waiting for deletions to finish 2025/05/04 05:46:24 INFO : sub: Set directory modification time (using DirSetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dozoqax1kegu'", Local "Local file system at /tmp/rclone3598271736", Modify Window "1ms" 2025/05/04 05:46:25 DEBUG : potato: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/05/04 05:46:25 DEBUG : potato: Unchanged skipping 2025/05/04 05:46:25 INFO : sub: Set directory modification time (using SetModTime) 2025/05/04 05:46:25 DEBUG : Added delayed dir = "sub", newDst=sub 2025/05/04 05:46:25 INFO : Encrypted drive 'TestCryptDrive:rclone-test-dozoqax1kegu': Making map for --track-renames 2025/05/04 05:46:25 INFO : Encrypted drive 'TestCryptDrive:rclone-test-dozoqax1kegu': Finished making map for --track-renames 2025/05/04 05:46:25 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dozoqax1kegu': Waiting for checks to finish 2025/05/04 05:46:25 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dozoqax1kegu': Waiting for renames to finish 2025/05/04 05:46:26 INFO : sub/yam: Moved (server-side) to: yam 2025/05/04 05:46:26 INFO : yam: Renamed from "sub/yam" 2025/05/04 05:46:26 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dozoqax1kegu': Waiting for transfers to finish 2025/05/04 05:46:26 DEBUG : Waiting for deletions to finish 2025/05/04 05:46:26 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dozoqax1kegu'", Local "Local file system at /tmp/rclone3598271736", Modify Window "1ms" --- PASS: TestSyncWithTrackRenamesStrategyLeaf (8.57s) === RUN TestServerSideMoveLocal run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dozoqax1kegu'", Local "Local file system at /tmp/rclone3598271736", Modify Window "1ms" 2025/05/04 05:46:30 DEBUG : Creating backend with remote "/tmp/rclone3598271736/dir1" 2025/05/04 05:46:30 DEBUG : Creating backend with remote "/tmp/rclone3598271736/dir2" 2025/05/04 05:46:30 DEBUG : Local file system at /tmp/rclone3598271736/dir2: Using server-side directory move 2025/05/04 05:46:30 INFO : Local file system at /tmp/rclone3598271736/dir2: Server side directory move failed - fallback to file moves: can't copy directory - destination already exists 2025/05/04 05:46:30 DEBUG : file1.txt: Need to transfer - File not found at Destination 2025/05/04 05:46:30 INFO : file1.txt: Moved (server-side) 2025/05/04 05:46:30 DEBUG : Local file system at /tmp/rclone3598271736/dir2: Waiting for checks to finish 2025/05/04 05:46:30 DEBUG : Local file system at /tmp/rclone3598271736/dir2: Waiting for transfers to finish --- PASS: TestServerSideMoveLocal (0.41s) === RUN TestMoveWithDeleteEmptySrcDirs run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dozoqax1kegu'", Local "Local file system at /tmp/rclone3598271736", Modify Window "1ms" 2025/05/04 05:46:30 DEBUG : Added delayed dir = "nested", newDst= 2025/05/04 05:46:30 DEBUG : Added delayed dir = "sub dir", newDst= 2025/05/04 05:46:30 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2025/05/04 05:46:30 DEBUG : Added delayed dir = "nested/sub dir", newDst= 2025/05/04 05:46:30 DEBUG : nested/sub dir/file: Need to transfer - File not found at Destination 2025/05/04 05:46:30 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dozoqax1kegu': Waiting for checks to finish 2025/05/04 05:46:30 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dozoqax1kegu': Waiting for transfers to finish 2025/05/04 05:46:32 DEBUG : sub dir/hello world: md5 = d77fdaeef245b3a345ac6140bba5cfee OK 2025/05/04 05:46:32 INFO : sub dir/hello world: Copied (new) 2025/05/04 05:46:32 INFO : sub dir/hello world: Deleted 2025/05/04 05:46:34 DEBUG : nested/sub dir/file: md5 = d4f0a705f25968cee3b96ca148dbe032 OK 2025/05/04 05:46:34 INFO : nested/sub dir/file: Copied (new) 2025/05/04 05:46:34 INFO : nested/sub dir/file: Deleted 2025/05/04 05:46:35 INFO : nested/sub dir: Set directory modification time (using DirSetModTime) 2025/05/04 05:46:35 INFO : sub dir: Set directory modification time (using DirSetModTime) 2025/05/04 05:46:35 INFO : nested: Set directory modification time (using DirSetModTime) 2025/05/04 05:46:35 INFO : sub dir: Removing directory 2025/05/04 05:46:35 INFO : nested/sub dir: Removing directory 2025/05/04 05:46:35 INFO : nested: Removing directory 2025/05/04 05:46:35 DEBUG : Local file system at /tmp/rclone3598271736: deleted 3 directories run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dozoqax1kegu'", Local "Local file system at /tmp/rclone3598271736", Modify Window "1ms" 2025/05/04 05:46:38 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" 2025/05/04 05:46:38 DEBUG : 37qp6d1gohacv723ij3brofbu8/14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "ftp4kuv8se7tqduu6pmmcvjsmk" 2025/05/04 05:46:39 DEBUG : 37qp6d1gohacv723ij3brofbu8: Rmdir: contains trashed file: "14begaa36ih249fgrnfk6nulg0" --- PASS: TestMoveWithDeleteEmptySrcDirs (10.11s) === RUN TestMoveWithoutDeleteEmptySrcDirs run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dozoqax1kegu'", Local "Local file system at /tmp/rclone3598271736", Modify Window "1ms" 2025/05/04 05:46:40 DEBUG : Added delayed dir = "nested", newDst= 2025/05/04 05:46:40 DEBUG : Added delayed dir = "sub dir", newDst= 2025/05/04 05:46:40 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2025/05/04 05:46:40 DEBUG : Added delayed dir = "nested/sub dir", newDst= 2025/05/04 05:46:40 DEBUG : nested/sub dir/file: Need to transfer - File not found at Destination 2025/05/04 05:46:40 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dozoqax1kegu': Waiting for checks to finish 2025/05/04 05:46:40 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dozoqax1kegu': Waiting for transfers to finish 2025/05/04 05:46:42 DEBUG : sub dir/hello world: md5 = 7ac275aff86d2690d5b34ee6093c0f39 OK 2025/05/04 05:46:42 INFO : sub dir/hello world: Copied (new) 2025/05/04 05:46:42 INFO : sub dir/hello world: Deleted 2025/05/04 05:46:44 DEBUG : nested/sub dir/file: md5 = 642029d0528564ed2f1c61cd7d17702f OK 2025/05/04 05:46:44 INFO : nested/sub dir/file: Copied (new) 2025/05/04 05:46:44 INFO : nested/sub dir/file: Deleted 2025/05/04 05:46:44 INFO : nested/sub dir: Set directory modification time (using DirSetModTime) 2025/05/04 05:46:45 INFO : nested: Set directory modification time (using DirSetModTime) 2025/05/04 05:46:45 INFO : sub dir: Set directory modification time (using DirSetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dozoqax1kegu'", Local "Local file system at /tmp/rclone3598271736", Modify Window "1ms" 2025/05/04 05:46:47 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" 2025/05/04 05:46:48 DEBUG : 37qp6d1gohacv723ij3brofbu8/14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "ftp4kuv8se7tqduu6pmmcvjsmk" 2025/05/04 05:46:48 DEBUG : 37qp6d1gohacv723ij3brofbu8: Rmdir: contains trashed file: "14begaa36ih249fgrnfk6nulg0" --- PASS: TestMoveWithoutDeleteEmptySrcDirs (9.34s) === RUN TestMoveWithIgnoreExisting run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dozoqax1kegu'", Local "Local file system at /tmp/rclone3598271736", Modify Window "1ms" 2025/05/04 05:46:50 DEBUG : existing: Need to transfer - File not found at Destination 2025/05/04 05:46:50 DEBUG : existing-b: Need to transfer - File not found at Destination 2025/05/04 05:46:50 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dozoqax1kegu': Waiting for checks to finish 2025/05/04 05:46:50 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dozoqax1kegu': Waiting for transfers to finish 2025/05/04 05:46:51 DEBUG : existing: md5 = fbba71de4d01dac327e7ddb43ba1a804 OK 2025/05/04 05:46:51 INFO : existing: Copied (new) 2025/05/04 05:46:51 INFO : existing: Deleted 2025/05/04 05:46:51 DEBUG : existing-b: md5 = 0f847769e7c5fb1d39cc51b38ef2d37f OK 2025/05/04 05:46:51 INFO : existing-b: Copied (new) 2025/05/04 05:46:51 INFO : existing-b: Deleted 2025/05/04 05:46:51 DEBUG : existing: Destination exists, skipping 2025/05/04 05:46:51 DEBUG : existing: Not removing source file as destination file exists and --ignore-existing is set 2025/05/04 05:46:51 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dozoqax1kegu': Waiting for checks to finish 2025/05/04 05:46:51 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dozoqax1kegu': Waiting for transfers to finish 2025/05/04 05:46:51 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dozoqax1kegu'", Local "Local file system at /tmp/rclone3598271736", Modify Window "1ms" --- PASS: TestMoveWithIgnoreExisting (4.12s) === RUN TestServerSideMove run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dozoqax1kegu'", Local "Local file system at /tmp/rclone3598271736", Modify Window "1ms" 2025/05/04 05:46:54 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-hidozid9tuma" 2025/05/04 05:46:54 DEBUG : Creating backend with remote "TestDrive:crypt/8heneolmefj0un0f5oct63tb8saqqgnajm4vtimrhcr420tjr4eg" 2025/05/04 05:46:56 DEBUG : potato2: md5 = a762d166d4b0aa1871a6b6f45686d797 OK 2025/05/04 05:46:57 DEBUG : empty space: md5 = b685963d492d44b17d57fc626b27e980 OK 2025/05/04 05:46:58 DEBUG : potato3: md5 = 90f5caebad8be95cfeafa8c8640ccf0f OK sync_test.go:1705: Server side move (if possible) Encrypted drive 'TestCryptDrive:rclone-test-dozoqax1kegu' -> Encrypted drive 'TestCryptDrive:rclone-test-hidozid9tuma' 2025/05/04 05:47:01 DEBUG : empty space: md5 = 3272ba41558258793991ba90c6c68786 OK 2025/05/04 05:47:02 DEBUG : potato3: md5 = 1df69ff5594038ac4e2f301ac6927006 OK 2025/05/04 05:47:02 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hidozid9tuma': Using server-side directory move 2025/05/04 05:47:02 INFO : Encrypted drive 'TestCryptDrive:rclone-test-hidozid9tuma': Server side directory move failed - fallback to file moves: can't copy directory - destination already exists 2025/05/04 05:47:02 DEBUG : potato2: Need to transfer - File not found at Destination 2025/05/04 05:47:02 DEBUG : empty space: Size and modification time the same (differ by 0s, within tolerance 1ms) 2025/05/04 05:47:02 DEBUG : empty space: Unchanged skipping 2025/05/04 05:47:02 DEBUG : potato3: Sizes differ (src 68 vs dst 60) 2025/05/04 05:47:02 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hidozid9tuma': Waiting for checks to finish 2025/05/04 05:47:03 INFO : potato3: Deleted 2025/05/04 05:47:03 INFO : empty space: Deleted 2025/05/04 05:47:03 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hidozid9tuma': Waiting for transfers to finish 2025/05/04 05:47:03 INFO : potato2: Moved (server-side) 2025/05/04 05:47:03 INFO : potato3: Moved (server-side) 2025/05/04 05:47:04 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-xilesin4kice" 2025/05/04 05:47:04 DEBUG : Creating backend with remote "TestDrive:crypt/8b5gsrrvn4qabccjdn4q286jjedfptbo4iditjg96qcuvq7d8m5g" 2025/05/04 05:47:05 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-xilesin4kice': Using server-side directory move 2025/05/04 05:47:06 INFO : Encrypted drive 'TestCryptDrive:rclone-test-xilesin4kice': Server side directory move succeeded 2025/05/04 05:47:07 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-xilesin4kice': Purge remote 2025/05/04 05:47:07 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hidozid9tuma': Purge remote 2025/05/04 05:47:07 NOTICE: purge failed: directory not found --- PASS: TestServerSideMove (14.10s) === RUN TestServerSideMoveWithFilter run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dozoqax1kegu'", Local "Local file system at /tmp/rclone3598271736", Modify Window "1ms" 2025/05/04 05:47:08 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-zakeped0picu" 2025/05/04 05:47:08 DEBUG : Creating backend with remote "TestDrive:crypt/o8697n2ve33vuglpqqmjh4fs9mcnrdbb5dq79f9h82uu5bn7gpn0" 2025/05/04 05:47:10 DEBUG : potato2: md5 = 66bb3a1fb4b535949738cbfb2016dd07 OK 2025/05/04 05:47:11 DEBUG : empty space: md5 = f08d9d69c7b4054a6209912c3901796e OK 2025/05/04 05:47:12 DEBUG : potato3: md5 = 7fe1088b4a6338fc2e675212474b1f83 OK sync_test.go:1705: Server side move (if possible) Encrypted drive 'TestCryptDrive:rclone-test-dozoqax1kegu' -> Encrypted drive 'TestCryptDrive:rclone-test-zakeped0picu' 2025/05/04 05:47:15 DEBUG : empty space: md5 = a546dcb50761f83aa4f867184aaf2aac OK 2025/05/04 05:47:16 DEBUG : potato3: md5 = 25b5629513c3823128dcd3672574426f OK 2025/05/04 05:47:16 DEBUG : empty space: Excluded (Size Filter) 2025/05/04 05:47:17 DEBUG : empty space: Excluded (Size Filter) 2025/05/04 05:47:17 DEBUG : potato2: Need to transfer - File not found at Destination 2025/05/04 05:47:17 DEBUG : potato3: Sizes differ (src 68 vs dst 60) 2025/05/04 05:47:17 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zakeped0picu': Waiting for checks to finish 2025/05/04 05:47:17 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zakeped0picu': Waiting for transfers to finish 2025/05/04 05:47:17 INFO : potato3: Deleted 2025/05/04 05:47:17 INFO : potato2: Moved (server-side) 2025/05/04 05:47:18 INFO : potato3: Moved (server-side) 2025/05/04 05:47:18 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-xudefux1hipo" 2025/05/04 05:47:18 DEBUG : Creating backend with remote "TestDrive:crypt/shdms7anu7d7k9lsbdg3m68tposg952md1nvtmgpqnaojms1g94g" 2025/05/04 05:47:19 DEBUG : empty space: Excluded (Size Filter) 2025/05/04 05:47:19 DEBUG : potato2: Need to transfer - File not found at Destination 2025/05/04 05:47:19 DEBUG : potato3: Need to transfer - File not found at Destination 2025/05/04 05:47:19 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-xudefux1hipo': Waiting for checks to finish 2025/05/04 05:47:19 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-xudefux1hipo': Waiting for transfers to finish 2025/05/04 05:47:20 INFO : potato3: Moved (server-side) 2025/05/04 05:47:21 INFO : potato2: Moved (server-side) 2025/05/04 05:47:21 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-xudefux1hipo': Purge remote 2025/05/04 05:47:22 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zakeped0picu': Purge remote --- PASS: TestServerSideMoveWithFilter (15.22s) === RUN TestServerSideMoveDeleteEmptySourceDirs run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dozoqax1kegu'", Local "Local file system at /tmp/rclone3598271736", Modify Window "1ms" 2025/05/04 05:47:23 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-pabikah3diki" 2025/05/04 05:47:23 DEBUG : Creating backend with remote "TestDrive:crypt/h48rjgb6j3mrr9t9alq9mfun69er2dv5dod4rn0vioiqbgs0q0og" 2025/05/04 05:47:25 DEBUG : potato2: md5 = 6c41e738dd8df15f7efdeb8397d11515 OK 2025/05/04 05:47:26 DEBUG : empty space: md5 = 93cb7900113c987549263b2e6261ecc8 OK 2025/05/04 05:47:28 DEBUG : potato3: md5 = cf8e85603610288d49b446b9bc7fcbe4 OK 2025/05/04 05:47:28 INFO : tomatoDir: Making directory sync_test.go:1705: Server side move (if possible) Encrypted drive 'TestCryptDrive:rclone-test-dozoqax1kegu' -> Encrypted drive 'TestCryptDrive:rclone-test-pabikah3diki' 2025/05/04 05:47:31 DEBUG : empty space: md5 = 845d80f4ceab5b3d191a77c74d3f3d18 OK 2025/05/04 05:47:32 DEBUG : potato3: md5 = 66b583772288368ad368ef6d0e6ba861 OK 2025/05/04 05:47:32 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pabikah3diki': Using server-side directory move 2025/05/04 05:47:32 INFO : Encrypted drive 'TestCryptDrive:rclone-test-pabikah3diki': Server side directory move failed - fallback to file moves: can't copy directory - destination already exists 2025/05/04 05:47:33 DEBUG : potato2: Need to transfer - File not found at Destination 2025/05/04 05:47:33 DEBUG : Added delayed dir = "tomatoDir", newDst= 2025/05/04 05:47:33 DEBUG : empty space: Size and modification time the same (differ by 0s, within tolerance 1ms) 2025/05/04 05:47:33 DEBUG : empty space: Unchanged skipping 2025/05/04 05:47:33 DEBUG : potato3: Sizes differ (src 68 vs dst 60) 2025/05/04 05:47:33 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pabikah3diki': Waiting for checks to finish 2025/05/04 05:47:33 INFO : potato3: Deleted 2025/05/04 05:47:33 INFO : empty space: Deleted 2025/05/04 05:47:33 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pabikah3diki': Waiting for transfers to finish 2025/05/04 05:47:33 INFO : potato2: Moved (server-side) 2025/05/04 05:47:34 INFO : potato3: Moved (server-side) 2025/05/04 05:47:34 INFO : tomatoDir: Removing directory 2025/05/04 05:47:34 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dozoqax1kegu': deleted 1 directories 2025/05/04 05:47:35 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-difemod5riri" 2025/05/04 05:47:35 DEBUG : Creating backend with remote "TestDrive:crypt/65ehktb95g8gjn21t1hfdfot9igplumjh8beofko95vmcfj1538g" 2025/05/04 05:47:36 INFO : tomatoDir: Making directory 2025/05/04 05:47:36 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-difemod5riri': Using server-side directory move 2025/05/04 05:47:37 INFO : Encrypted drive 'TestCryptDrive:rclone-test-difemod5riri': Server side directory move succeeded 2025/05/04 05:47:39 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-difemod5riri': Purge remote 2025/05/04 05:47:39 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pabikah3diki': Purge remote 2025/05/04 05:47:39 NOTICE: purge failed: directory not found --- PASS: TestServerSideMoveDeleteEmptySourceDirs (16.69s) === RUN TestServerSideMoveOverlap run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dozoqax1kegu'", Local "Local file system at /tmp/rclone3598271736", Modify Window "1ms" sync_test.go:1910: Skipping test as remote supports DirMove --- SKIP: TestServerSideMoveOverlap (0.43s) === RUN TestSyncOverlap run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dozoqax1kegu'", Local "Local file system at /tmp/rclone3598271736", Modify Window "1ms" 2025/05/04 05:47:40 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-dozoqax1kegu/rclone-sync-test" 2025/05/04 05:47:40 DEBUG : Creating backend with remote "TestDrive:crypt/cpul26lr8ek8vhk8j66soansr0gvmba19g0oli717lmu0de2ir60/i7355aa0sb89uagn75vfjqr6s3e3e1h2et8in57abn1fe8qfego0" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dozoqax1kegu'", Local "Local file system at /tmp/rclone3598271736", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dozoqax1kegu'", Local "Local file system at /tmp/rclone3598271736", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dozoqax1kegu'", Local "Local file system at /tmp/rclone3598271736", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dozoqax1kegu'", Local "Local file system at /tmp/rclone3598271736", Modify Window "1ms" --- PASS: TestSyncOverlap (3.58s) === RUN TestSyncOverlapWithFilter run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dozoqax1kegu'", Local "Local file system at /tmp/rclone3598271736", Modify Window "1ms" 2025/05/04 05:47:44 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-dozoqax1kegu/rclone-sync-test" 2025/05/04 05:47:44 DEBUG : Creating backend with remote "TestDrive:crypt/cpul26lr8ek8vhk8j66soansr0gvmba19g0oli717lmu0de2ir60/i7355aa0sb89uagn75vfjqr6s3e3e1h2et8in57abn1fe8qfego0" 2025/05/04 05:47:46 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-dozoqax1kegu/rclone-sync-test-include/layer2" 2025/05/04 05:47:46 DEBUG : Creating backend with remote "TestDrive:crypt/cpul26lr8ek8vhk8j66soansr0gvmba19g0oli717lmu0de2ir60/khf2vlblvnbf9ftevqm0htmss73hj1j5a7q328e4ohrgs7e2loe0/n01jpl9202nn9ec1rb75h0f1c4" 2025/05/04 05:47:49 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-dozoqax1kegu/rclone-sync-test-ignore-file" 2025/05/04 05:47:49 DEBUG : Creating backend with remote "TestDrive:crypt/cpul26lr8ek8vhk8j66soansr0gvmba19g0oli717lmu0de2ir60/kmf11jujl9uha3tjganvgpkn45bu778hb5vb5riug1c26b38k7sg" 2025/05/04 05:47:52 DEBUG : rclone-sync-test-ignore-file/.ignore: md5 = 6f16d481a792d73824fd009b503a3f67 OK 2025/05/04 05:47:54 DEBUG : Added delayed dir = "rclone-sync-test-include", newDst= 2025/05/04 05:47:54 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dozoqax1kegu/rclone-sync-test': Waiting for checks to finish 2025/05/04 05:47:54 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dozoqax1kegu/rclone-sync-test': Waiting for transfers to finish 2025/05/04 05:47:54 DEBUG : Waiting for deletions to finish 2025/05/04 05:47:54 INFO : There was nothing to transfer 2025/05/04 05:47:56 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dozoqax1kegu': Waiting for checks to finish 2025/05/04 05:47:56 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dozoqax1kegu': Waiting for transfers to finish 2025/05/04 05:47:56 DEBUG : Waiting for deletions to finish 2025/05/04 05:47:56 INFO : rclone-sync-test-include: Removing directory 2025/05/04 05:47:56 DEBUG : khf2vlblvnbf9ftevqm0htmss73hj1j5a7q328e4ohrgs7e2loe0: Rmdir: contains file: "n01jpl9202nn9ec1rb75h0f1c4" 2025/05/04 05:47:56 DEBUG : rclone-sync-test-include: Failed to Rmdir: directory not empty 2025/05/04 05:47:56 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dozoqax1kegu': failed to delete 1 directories 2025/05/04 05:47:56 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dozoqax1kegu'", Local "Local file system at /tmp/rclone3598271736", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dozoqax1kegu'", Local "Local file system at /tmp/rclone3598271736", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dozoqax1kegu'", Local "Local file system at /tmp/rclone3598271736", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dozoqax1kegu'", Local "Local file system at /tmp/rclone3598271736", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dozoqax1kegu'", Local "Local file system at /tmp/rclone3598271736", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dozoqax1kegu'", Local "Local file system at /tmp/rclone3598271736", Modify Window "1ms" 2025/05/04 05:47:58 DEBUG : Added delayed dir = "rclone-sync-test-include", newDst= 2025/05/04 05:47:58 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dozoqax1kegu/rclone-sync-test-include/layer2': Waiting for checks to finish 2025/05/04 05:47:58 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dozoqax1kegu/rclone-sync-test-include/layer2': Waiting for transfers to finish 2025/05/04 05:47:58 DEBUG : Waiting for deletions to finish 2025/05/04 05:47:58 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dozoqax1kegu'", Local "Local file system at /tmp/rclone3598271736", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dozoqax1kegu'", Local "Local file system at /tmp/rclone3598271736", Modify Window "1ms" 2025/05/04 05:48:00 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dozoqax1kegu': Waiting for checks to finish 2025/05/04 05:48:00 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dozoqax1kegu': Waiting for transfers to finish 2025/05/04 05:48:00 DEBUG : Waiting for deletions to finish 2025/05/04 05:48:00 INFO : rclone-sync-test-include: Removing directory 2025/05/04 05:48:00 DEBUG : khf2vlblvnbf9ftevqm0htmss73hj1j5a7q328e4ohrgs7e2loe0: Rmdir: contains file: "n01jpl9202nn9ec1rb75h0f1c4" 2025/05/04 05:48:00 DEBUG : rclone-sync-test-include: Failed to Rmdir: directory not empty 2025/05/04 05:48:00 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dozoqax1kegu': failed to delete 1 directories 2025/05/04 05:48:00 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dozoqax1kegu'", Local "Local file system at /tmp/rclone3598271736", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dozoqax1kegu'", Local "Local file system at /tmp/rclone3598271736", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dozoqax1kegu'", Local "Local file system at /tmp/rclone3598271736", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dozoqax1kegu'", Local "Local file system at /tmp/rclone3598271736", Modify Window "1ms" 2025/05/04 05:48:02 DEBUG : Added delayed dir = "rclone-sync-test-include", newDst= 2025/05/04 05:48:02 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dozoqax1kegu/rclone-sync-test-ignore-file': Waiting for checks to finish 2025/05/04 05:48:02 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dozoqax1kegu/rclone-sync-test-ignore-file': Waiting for transfers to finish 2025/05/04 05:48:02 DEBUG : Waiting for deletions to finish 2025/05/04 05:48:02 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dozoqax1kegu'", Local "Local file system at /tmp/rclone3598271736", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dozoqax1kegu'", Local "Local file system at /tmp/rclone3598271736", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dozoqax1kegu'", Local "Local file system at /tmp/rclone3598271736", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dozoqax1kegu'", Local "Local file system at /tmp/rclone3598271736", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dozoqax1kegu'", Local "Local file system at /tmp/rclone3598271736", Modify Window "1ms" 2025/05/04 05:48:04 DEBUG : khf2vlblvnbf9ftevqm0htmss73hj1j5a7q328e4ohrgs7e2loe0: Rmdir: contains trashed file: "n01jpl9202nn9ec1rb75h0f1c4" 2025/05/04 05:48:04 DEBUG : kmf11jujl9uha3tjganvgpkn45bu778hb5vb5riug1c26b38k7sg: Rmdir: contains trashed file: "i0t74httmdlljg425j6tg570d8" --- PASS: TestSyncOverlapWithFilter (29.06s) === RUN TestSyncCompareDest run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dozoqax1kegu'", Local "Local file system at /tmp/rclone3598271736", Modify Window "1ms" 2025/05/04 05:48:13 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-dozoqax1kegu/dst" 2025/05/04 05:48:13 DEBUG : Creating backend with remote "TestDrive:crypt/cpul26lr8ek8vhk8j66soansr0gvmba19g0oli717lmu0de2ir60/31u3jie661vd5p8j7rtc3hgbh0" 2025/05/04 05:48:14 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-dozoqax1kegu/CompareDest" 2025/05/04 05:48:14 DEBUG : Creating backend with remote "TestDrive:crypt/cpul26lr8ek8vhk8j66soansr0gvmba19g0oli717lmu0de2ir60/gveqi14airsml4bgu7krj116o8" 2025/05/04 05:48:16 DEBUG : one: Need to transfer - File not found at Destination 2025/05/04 05:48:16 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dozoqax1kegu/dst': Waiting for checks to finish 2025/05/04 05:48:16 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dozoqax1kegu/dst': Waiting for transfers to finish 2025/05/04 05:48:18 DEBUG : one: md5 = eb989a4b60ae47696f54fd8b3d76f72e OK 2025/05/04 05:48:18 INFO : one: Copied (new) 2025/05/04 05:48:18 DEBUG : Waiting for deletions to finish 2025/05/04 05:48:19 DEBUG : one: Sizes differ (src 5 vs dst 3) 2025/05/04 05:48:19 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dozoqax1kegu/dst': Waiting for checks to finish 2025/05/04 05:48:20 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dozoqax1kegu/dst': Waiting for transfers to finish 2025/05/04 05:48:21 DEBUG : one: md5 = 01b5c19646dff8382c855f38cfa80a57 OK 2025/05/04 05:48:21 INFO : one: Copied (replaced existing) 2025/05/04 05:48:21 DEBUG : Waiting for deletions to finish 2025/05/04 05:48:23 DEBUG : dst/one: md5 = 7c8135f2b429ef7f2429e96cd6cf6396 OK 2025/05/04 05:48:25 DEBUG : CompareDest/one: md5 = 504fa433e1a0753fa6453db1864f4dc0 OK 2025/05/04 05:48:25 DEBUG : one: Sizes differ (src 5 vs dst 3) 2025/05/04 05:48:25 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dozoqax1kegu/dst': Waiting for checks to finish 2025/05/04 05:48:26 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/05/04 05:48:26 DEBUG : one: Destination found in --compare-dest, skipping 2025/05/04 05:48:26 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dozoqax1kegu/dst': Waiting for transfers to finish 2025/05/04 05:48:26 DEBUG : Waiting for deletions to finish 2025/05/04 05:48:26 INFO : There was nothing to transfer 2025/05/04 05:48:28 DEBUG : CompareDest/two: md5 = bf2431dddf48578a6b6bca534dbe82d6 OK 2025/05/04 05:48:29 DEBUG : one: Sizes differ (src 5 vs dst 3) 2025/05/04 05:48:29 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/05/04 05:48:29 DEBUG : one: Destination found in --compare-dest, skipping 2025/05/04 05:48:29 DEBUG : two: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/05/04 05:48:29 DEBUG : two: Destination found in --compare-dest, skipping 2025/05/04 05:48:29 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dozoqax1kegu/dst': Waiting for checks to finish 2025/05/04 05:48:29 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dozoqax1kegu/dst': Waiting for transfers to finish 2025/05/04 05:48:29 DEBUG : Waiting for deletions to finish 2025/05/04 05:48:29 INFO : There was nothing to transfer 2025/05/04 05:48:30 DEBUG : one: Sizes differ (src 5 vs dst 3) 2025/05/04 05:48:30 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/05/04 05:48:30 DEBUG : one: Destination found in --compare-dest, skipping 2025/05/04 05:48:30 DEBUG : two: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/05/04 05:48:30 DEBUG : two: Destination found in --compare-dest, skipping 2025/05/04 05:48:30 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dozoqax1kegu/dst': Waiting for checks to finish 2025/05/04 05:48:30 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dozoqax1kegu/dst': Waiting for transfers to finish 2025/05/04 05:48:30 DEBUG : Waiting for deletions to finish 2025/05/04 05:48:30 INFO : There was nothing to transfer sync_test.go:2175: No hash on uploaded file so skipping compare timestamp test 2025/05/04 05:48:31 DEBUG : one: Sizes differ (src 5 vs dst 3) 2025/05/04 05:48:31 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/05/04 05:48:31 DEBUG : one: Destination found in --compare-dest, skipping 2025/05/04 05:48:31 DEBUG : two: Sizes differ (src 5 vs dst 3) 2025/05/04 05:48:31 DEBUG : two: Need to transfer - File not found at Destination 2025/05/04 05:48:31 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dozoqax1kegu/dst': Waiting for checks to finish 2025/05/04 05:48:31 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dozoqax1kegu/dst': Waiting for transfers to finish 2025/05/04 05:48:33 DEBUG : two: md5 = 0837c70e9eed88c7240fe0cf3dcff944 OK 2025/05/04 05:48:33 INFO : two: Copied (new) 2025/05/04 05:48:33 DEBUG : Waiting for deletions to finish 2025/05/04 05:48:35 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k" 2025/05/04 05:48:35 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" 2025/05/04 05:48:36 DEBUG : gveqi14airsml4bgu7krj116o8: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k" 2025/05/04 05:48:36 DEBUG : gveqi14airsml4bgu7krj116o8: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" --- PASS: TestSyncCompareDest (24.01s) === RUN TestSyncMultipleCompareDest run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dozoqax1kegu'", Local "Local file system at /tmp/rclone3598271736", Modify Window "1ms" 2025/05/04 05:48:38 DEBUG : pre-dest1/1: md5 = 4f9b8143d2610fa2a56c810a2e3eba7c OK 2025/05/04 05:48:40 DEBUG : pre-dest2/2: md5 = 516b02ba13005b58c737e4aaa206639f OK 2025/05/04 05:48:41 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-dozoqax1kegu/dest" 2025/05/04 05:48:41 DEBUG : Creating backend with remote "TestDrive:crypt/cpul26lr8ek8vhk8j66soansr0gvmba19g0oli717lmu0de2ir60/rg03c1jvnehrrc617i0lnqjddc" 2025/05/04 05:48:42 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-dozoqax1kegu/pre-dest1" 2025/05/04 05:48:43 DEBUG : Creating backend with remote "TestDrive:crypt/cpul26lr8ek8vhk8j66soansr0gvmba19g0oli717lmu0de2ir60/bbnblvh6k061ssopqrp18kd7gc" 2025/05/04 05:48:43 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-dozoqax1kegu/pre-dest2" 2025/05/04 05:48:43 DEBUG : Creating backend with remote "TestDrive:crypt/cpul26lr8ek8vhk8j66soansr0gvmba19g0oli717lmu0de2ir60/dgicm1h6b5ejvlltm8eeif0bnk" 2025/05/04 05:48:44 DEBUG : 1: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/05/04 05:48:44 DEBUG : 1: Destination found in --compare-dest, skipping 2025/05/04 05:48:45 DEBUG : 2: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/05/04 05:48:45 DEBUG : 2: Destination found in --compare-dest, skipping 2025/05/04 05:48:45 DEBUG : 3: Need to transfer - File not found at Destination 2025/05/04 05:48:45 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dozoqax1kegu/dest': Waiting for checks to finish 2025/05/04 05:48:45 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dozoqax1kegu/dest': Waiting for transfers to finish 2025/05/04 05:48:47 DEBUG : 3: md5 = ab90fc227ab14d967c79a094c8cd23f7 OK 2025/05/04 05:48:47 INFO : 3: Copied (new) 2025/05/04 05:48:47 DEBUG : Waiting for deletions to finish 2025/05/04 05:48:50 DEBUG : dgicm1h6b5ejvlltm8eeif0bnk: Rmdir: contains trashed file: "1ghu8geql9vrl726n32nrf65bc" 2025/05/04 05:48:51 DEBUG : bbnblvh6k061ssopqrp18kd7gc: Rmdir: contains trashed file: "skbfko3oil7es0lj68ob574sro" 2025/05/04 05:48:51 DEBUG : rg03c1jvnehrrc617i0lnqjddc: Rmdir: contains trashed file: "g072p7hmjchlnj0gibe64c1epg" --- PASS: TestSyncMultipleCompareDest (15.44s) === RUN TestSyncCopyDest run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dozoqax1kegu'", Local "Local file system at /tmp/rclone3598271736", Modify Window "1ms" 2025/05/04 05:48:52 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-dozoqax1kegu/dst" 2025/05/04 05:48:52 DEBUG : Creating backend with remote "TestDrive:crypt/cpul26lr8ek8vhk8j66soansr0gvmba19g0oli717lmu0de2ir60/31u3jie661vd5p8j7rtc3hgbh0" 2025/05/04 05:48:54 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-dozoqax1kegu/CopyDest" 2025/05/04 05:48:54 DEBUG : Creating backend with remote "TestDrive:crypt/cpul26lr8ek8vhk8j66soansr0gvmba19g0oli717lmu0de2ir60/d09o6po3f7bm6ce32vdgs8h9ls" 2025/05/04 05:48:55 DEBUG : one: Need to transfer - File not found at Destination 2025/05/04 05:48:55 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dozoqax1kegu/dst': Waiting for checks to finish 2025/05/04 05:48:55 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dozoqax1kegu/dst': Waiting for transfers to finish 2025/05/04 05:48:57 DEBUG : one: md5 = 7d00a3b03b5a19f5487f786dc641e9e6 OK 2025/05/04 05:48:57 INFO : one: Copied (new) 2025/05/04 05:48:57 DEBUG : Waiting for deletions to finish 2025/05/04 05:48:58 DEBUG : one: Sizes differ (src 5 vs dst 3) 2025/05/04 05:48:58 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dozoqax1kegu/dst': Waiting for checks to finish 2025/05/04 05:48:59 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dozoqax1kegu/dst': Waiting for transfers to finish 2025/05/04 05:49:00 DEBUG : one: md5 = 2d8f92492fbb12ff5110de56358f7d45 OK 2025/05/04 05:49:00 INFO : one: Copied (replaced existing) 2025/05/04 05:49:00 DEBUG : Waiting for deletions to finish 2025/05/04 05:49:02 DEBUG : dst/one: md5 = db4f5bddc76071ea97fa4e1522696ba8 OK 2025/05/04 05:49:04 DEBUG : CopyDest/one: md5 = c0da5b6b06d4c6184a0ebccbef38b587 OK 2025/05/04 05:49:04 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-dozoqax1kegu/BackupDir" 2025/05/04 05:49:04 DEBUG : Creating backend with remote "TestDrive:crypt/cpul26lr8ek8vhk8j66soansr0gvmba19g0oli717lmu0de2ir60/s6dbk3lfi7c9kfvo6j7bla9m0g" 2025/05/04 05:49:06 DEBUG : one: Sizes differ (src 5 vs dst 3) 2025/05/04 05:49:06 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dozoqax1kegu/dst': Waiting for checks to finish 2025/05/04 05:49:06 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/05/04 05:49:06 DEBUG : one: Sizes differ (src 5 vs dst 3) 2025/05/04 05:49:08 INFO : one: Moved (server-side) 2025/05/04 05:49:09 INFO : one: Copied (server-side copy) 2025/05/04 05:49:09 DEBUG : one: Destination found in --copy-dest, using server-side copy 2025/05/04 05:49:09 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dozoqax1kegu/dst': Waiting for transfers to finish 2025/05/04 05:49:09 DEBUG : Waiting for deletions to finish 2025/05/04 05:49:10 DEBUG : CopyDest/two: md5 = 35cf48e9c495f27059a414dcac950b8e OK 2025/05/04 05:49:11 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/05/04 05:49:11 DEBUG : one: Unchanged skipping 2025/05/04 05:49:11 DEBUG : two: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/05/04 05:49:12 INFO : two: Copied (server-side copy) 2025/05/04 05:49:12 DEBUG : two: Destination found in --copy-dest, using server-side copy 2025/05/04 05:49:12 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dozoqax1kegu/dst': Waiting for checks to finish 2025/05/04 05:49:12 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dozoqax1kegu/dst': Waiting for transfers to finish 2025/05/04 05:49:12 DEBUG : Waiting for deletions to finish 2025/05/04 05:49:13 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/05/04 05:49:13 DEBUG : one: Unchanged skipping 2025/05/04 05:49:13 DEBUG : two: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/05/04 05:49:13 DEBUG : two: Unchanged skipping 2025/05/04 05:49:13 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dozoqax1kegu/dst': Waiting for checks to finish 2025/05/04 05:49:13 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dozoqax1kegu/dst': Waiting for transfers to finish 2025/05/04 05:49:13 DEBUG : Waiting for deletions to finish 2025/05/04 05:49:13 INFO : There was nothing to transfer 2025/05/04 05:49:15 DEBUG : CopyDest/three: md5 = a6d72577d7ee97904232f6b6413a402f OK 2025/05/04 05:49:15 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/05/04 05:49:15 DEBUG : one: Unchanged skipping 2025/05/04 05:49:16 DEBUG : three: Sizes differ (src 7 vs dst 5) 2025/05/04 05:49:16 DEBUG : three: Destination not found in --copy-dest 2025/05/04 05:49:16 DEBUG : three: Need to transfer - File not found at Destination 2025/05/04 05:49:16 DEBUG : two: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/05/04 05:49:16 DEBUG : two: Unchanged skipping 2025/05/04 05:49:16 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dozoqax1kegu/dst': Waiting for checks to finish 2025/05/04 05:49:16 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dozoqax1kegu/dst': Waiting for transfers to finish 2025/05/04 05:49:17 DEBUG : three: md5 = 2133069a22d6425301e6e63efbc79cb9 OK 2025/05/04 05:49:17 INFO : three: Copied (new) 2025/05/04 05:49:17 DEBUG : Waiting for deletions to finish 2025/05/04 05:49:21 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "b6jdmn2b1adrhc8vikh7edr9os" 2025/05/04 05:49:21 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" 2025/05/04 05:49:21 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k" 2025/05/04 05:49:22 DEBUG : d09o6po3f7bm6ce32vdgs8h9ls: Rmdir: contains trashed file: "b6jdmn2b1adrhc8vikh7edr9os" 2025/05/04 05:49:22 DEBUG : d09o6po3f7bm6ce32vdgs8h9ls: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k" 2025/05/04 05:49:22 DEBUG : d09o6po3f7bm6ce32vdgs8h9ls: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" 2025/05/04 05:49:23 DEBUG : s6dbk3lfi7c9kfvo6j7bla9m0g: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" --- PASS: TestSyncCopyDest (31.13s) === RUN TestSyncBackupDir run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dozoqax1kegu'", Local "Local file system at /tmp/rclone3598271736", Modify Window "1ms" 2025/05/04 05:49:25 DEBUG : dst/one: md5 = 5eca1b503581f183eda21c1cabf9071e OK 2025/05/04 05:49:26 DEBUG : dst/two: md5 = c1ab40297f69fcc44bbb65bc70cd1d0f OK 2025/05/04 05:49:28 DEBUG : dst/three.txt: md5 = 2199c2f2f8d57f506f1a6c9379b9c71a OK 2025/05/04 05:49:28 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-dozoqax1kegu/dst" 2025/05/04 05:49:28 DEBUG : Creating backend with remote "TestDrive:crypt/cpul26lr8ek8vhk8j66soansr0gvmba19g0oli717lmu0de2ir60/31u3jie661vd5p8j7rtc3hgbh0" 2025/05/04 05:49:29 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-dozoqax1kegu/backup" 2025/05/04 05:49:29 DEBUG : Creating backend with remote "TestDrive:crypt/cpul26lr8ek8vhk8j66soansr0gvmba19g0oli717lmu0de2ir60/1nrff024r7pq65ecp72fc28jb0" 2025/05/04 05:49:31 DEBUG : one: Sizes differ (src 4 vs dst 3) 2025/05/04 05:49:31 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/05/04 05:49:31 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dozoqax1kegu/dst': Waiting for checks to finish 2025/05/04 05:49:31 DEBUG : two: Unchanged skipping 2025/05/04 05:49:32 INFO : one: Moved (server-side) 2025/05/04 05:49:32 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dozoqax1kegu/dst': Waiting for transfers to finish 2025/05/04 05:49:34 DEBUG : one: md5 = e5414c37fb6e295855dba59f2f0dc968 OK 2025/05/04 05:49:34 INFO : one: Copied (new) 2025/05/04 05:49:34 DEBUG : Waiting for deletions to finish 2025/05/04 05:49:34 INFO : three.txt: Moved (server-side) 2025/05/04 05:49:34 INFO : three.txt: Moved into backup dir 2025/05/04 05:49:36 DEBUG : dst/three.txt: md5 = 14463f06026de113676881c6a8e1d508 OK 2025/05/04 05:49:37 DEBUG : one: Sizes differ (src 5 vs dst 4) 2025/05/04 05:49:37 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/05/04 05:49:37 DEBUG : two: Unchanged skipping 2025/05/04 05:49:37 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dozoqax1kegu/dst': Waiting for checks to finish 2025/05/04 05:49:38 INFO : one: Deleted 2025/05/04 05:49:38 INFO : one: Moved (server-side) 2025/05/04 05:49:38 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dozoqax1kegu/dst': Waiting for transfers to finish 2025/05/04 05:49:39 DEBUG : one: md5 = ea0c899cd278ac427f3da39ad7730c90 OK 2025/05/04 05:49:39 INFO : one: Copied (new) 2025/05/04 05:49:39 DEBUG : Waiting for deletions to finish 2025/05/04 05:49:40 INFO : three.txt: Deleted 2025/05/04 05:49:40 INFO : three.txt: Moved (server-side) 2025/05/04 05:49:40 INFO : three.txt: Moved into backup dir 2025/05/04 05:49:43 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" 2025/05/04 05:49:43 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k" 2025/05/04 05:49:44 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "tr2hj63d80ftlmvm6a952snjcc" 2025/05/04 05:49:44 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" 2025/05/04 05:49:44 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "tr2hj63d80ftlmvm6a952snjcc" 2025/05/04 05:49:44 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" --- PASS: TestSyncBackupDir (21.41s) === RUN TestSyncBackupDirWithSuffix run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dozoqax1kegu'", Local "Local file system at /tmp/rclone3598271736", Modify Window "1ms" 2025/05/04 05:49:47 DEBUG : dst/one: md5 = 5613b03a4d0603f544bc8235b51e4e83 OK 2025/05/04 05:49:48 DEBUG : dst/two: md5 = fe306821c09b942a5e50a1907931eab7 OK 2025/05/04 05:49:49 DEBUG : dst/three.txt: md5 = 7811843bdadb62cb1d6f9635067d0252 OK 2025/05/04 05:49:50 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-dozoqax1kegu/dst" 2025/05/04 05:49:50 DEBUG : Creating backend with remote "TestDrive:crypt/cpul26lr8ek8vhk8j66soansr0gvmba19g0oli717lmu0de2ir60/31u3jie661vd5p8j7rtc3hgbh0" 2025/05/04 05:49:50 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-dozoqax1kegu/backup" 2025/05/04 05:49:51 DEBUG : Creating backend with remote "TestDrive:crypt/cpul26lr8ek8vhk8j66soansr0gvmba19g0oli717lmu0de2ir60/1nrff024r7pq65ecp72fc28jb0" 2025/05/04 05:49:52 DEBUG : one: Sizes differ (src 4 vs dst 3) 2025/05/04 05:49:52 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/05/04 05:49:52 DEBUG : two: Unchanged skipping 2025/05/04 05:49:52 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dozoqax1kegu/dst': Waiting for checks to finish 2025/05/04 05:49:54 INFO : one: Moved (server-side) to: one.bak 2025/05/04 05:49:54 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dozoqax1kegu/dst': Waiting for transfers to finish 2025/05/04 05:49:55 DEBUG : one: md5 = e688821daf426fd98b945b01a4a8f92b OK 2025/05/04 05:49:55 INFO : one: Copied (new) 2025/05/04 05:49:55 DEBUG : Waiting for deletions to finish 2025/05/04 05:49:56 INFO : three.txt: Moved (server-side) to: three.txt.bak 2025/05/04 05:49:56 INFO : three.txt: Moved into backup dir 2025/05/04 05:49:58 DEBUG : dst/three.txt: md5 = ff7a42e26e2bdadb7d73c3908cbdfedb OK 2025/05/04 05:49:58 DEBUG : one: Sizes differ (src 5 vs dst 4) 2025/05/04 05:49:58 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/05/04 05:49:58 DEBUG : two: Unchanged skipping 2025/05/04 05:49:58 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dozoqax1kegu/dst': Waiting for checks to finish 2025/05/04 05:49:59 INFO : one.bak: Deleted 2025/05/04 05:50:00 INFO : one: Moved (server-side) to: one.bak 2025/05/04 05:50:00 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dozoqax1kegu/dst': Waiting for transfers to finish 2025/05/04 05:50:01 DEBUG : one: md5 = a910dced8fe12b6f6db99e8ba31de26d OK 2025/05/04 05:50:01 INFO : one: Copied (new) 2025/05/04 05:50:01 DEBUG : Waiting for deletions to finish 2025/05/04 05:50:02 INFO : three.txt.bak: Deleted 2025/05/04 05:50:03 INFO : three.txt: Moved (server-side) to: three.txt.bak 2025/05/04 05:50:03 INFO : three.txt: Moved into backup dir 2025/05/04 05:50:06 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" 2025/05/04 05:50:06 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k" 2025/05/04 05:50:07 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "qltcak2uaegtmcoa8vijdppbp8" 2025/05/04 05:50:07 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "sk91qgsqfn0r271r2ehsaoc20c" 2025/05/04 05:50:07 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "sk91qgsqfn0r271r2ehsaoc20c" 2025/05/04 05:50:07 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "qltcak2uaegtmcoa8vijdppbp8" --- PASS: TestSyncBackupDirWithSuffix (22.76s) === RUN TestSyncBackupDirWithSuffixKeepExtension run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dozoqax1kegu'", Local "Local file system at /tmp/rclone3598271736", Modify Window "1ms" 2025/05/04 05:50:10 DEBUG : dst/one: md5 = f5509e98682232be722c25ba3b02ea33 OK 2025/05/04 05:50:11 DEBUG : dst/two: md5 = a06d3f68dd392ea5a0d2112877a0c6ae OK 2025/05/04 05:50:12 DEBUG : dst/three.txt: md5 = 75cd87a5f750de2f3e8b24e32774f6f3 OK 2025/05/04 05:50:13 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-dozoqax1kegu/dst" 2025/05/04 05:50:13 DEBUG : Creating backend with remote "TestDrive:crypt/cpul26lr8ek8vhk8j66soansr0gvmba19g0oli717lmu0de2ir60/31u3jie661vd5p8j7rtc3hgbh0" 2025/05/04 05:50:14 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-dozoqax1kegu/backup" 2025/05/04 05:50:14 DEBUG : Creating backend with remote "TestDrive:crypt/cpul26lr8ek8vhk8j66soansr0gvmba19g0oli717lmu0de2ir60/1nrff024r7pq65ecp72fc28jb0" 2025/05/04 05:50:15 DEBUG : one: Sizes differ (src 4 vs dst 3) 2025/05/04 05:50:15 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/05/04 05:50:15 DEBUG : two: Unchanged skipping 2025/05/04 05:50:15 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dozoqax1kegu/dst': Waiting for checks to finish 2025/05/04 05:50:17 INFO : one: Moved (server-side) to: one-2019-01-01 2025/05/04 05:50:17 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dozoqax1kegu/dst': Waiting for transfers to finish 2025/05/04 05:50:18 DEBUG : one: md5 = 8e2b05b392648bf5850812196ee398a4 OK 2025/05/04 05:50:18 INFO : one: Copied (new) 2025/05/04 05:50:18 DEBUG : Waiting for deletions to finish 2025/05/04 05:50:19 INFO : three.txt: Moved (server-side) to: three-2019-01-01.txt 2025/05/04 05:50:19 INFO : three.txt: Moved into backup dir 2025/05/04 05:50:21 DEBUG : dst/three.txt: md5 = f7688e4518eec4e214d87f456dfad0b6 OK 2025/05/04 05:50:22 DEBUG : one: Sizes differ (src 5 vs dst 4) 2025/05/04 05:50:22 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/05/04 05:50:22 DEBUG : two: Unchanged skipping 2025/05/04 05:50:22 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dozoqax1kegu/dst': Waiting for checks to finish 2025/05/04 05:50:22 INFO : one-2019-01-01: Deleted 2025/05/04 05:50:23 INFO : one: Moved (server-side) to: one-2019-01-01 2025/05/04 05:50:23 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dozoqax1kegu/dst': Waiting for transfers to finish 2025/05/04 05:50:24 DEBUG : one: md5 = 1d4076f545b7200ee712e68ced00dbeb OK 2025/05/04 05:50:24 INFO : one: Copied (new) 2025/05/04 05:50:24 DEBUG : Waiting for deletions to finish 2025/05/04 05:50:25 INFO : three-2019-01-01.txt: Deleted 2025/05/04 05:50:26 INFO : three.txt: Moved (server-side) to: three-2019-01-01.txt 2025/05/04 05:50:26 INFO : three.txt: Moved into backup dir 2025/05/04 05:50:28 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" 2025/05/04 05:50:28 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k" 2025/05/04 05:50:29 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "jcjl1bv3ep0v8kt35lqql1co90" 2025/05/04 05:50:29 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "qtq2f6qq4lgpsmj88vb7147qje3prudmtfdtr2342fth58vo9a50" 2025/05/04 05:50:29 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "qtq2f6qq4lgpsmj88vb7147qje3prudmtfdtr2342fth58vo9a50" 2025/05/04 05:50:29 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "jcjl1bv3ep0v8kt35lqql1co90" --- PASS: TestSyncBackupDirWithSuffixKeepExtension (22.42s) === RUN TestSyncBackupDirSuffixOnly run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dozoqax1kegu'", Local "Local file system at /tmp/rclone3598271736", Modify Window "1ms" 2025/05/04 05:50:32 DEBUG : dst/one: md5 = 50fa15cbf62a5af146863ad9359782dc OK 2025/05/04 05:50:33 DEBUG : dst/two: md5 = 1bd693b5e2f8e23a7bf63fc28102b558 OK 2025/05/04 05:50:35 DEBUG : dst/three.txt: md5 = 3df2039adc586a743eb89b021df7e361 OK 2025/05/04 05:50:35 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-dozoqax1kegu/dst" 2025/05/04 05:50:35 DEBUG : Creating backend with remote "TestDrive:crypt/cpul26lr8ek8vhk8j66soansr0gvmba19g0oli717lmu0de2ir60/31u3jie661vd5p8j7rtc3hgbh0" 2025/05/04 05:50:36 DEBUG : one: Sizes differ (src 4 vs dst 3) 2025/05/04 05:50:36 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/05/04 05:50:36 DEBUG : two: Unchanged skipping 2025/05/04 05:50:36 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dozoqax1kegu/dst': Waiting for checks to finish 2025/05/04 05:50:37 INFO : one: Moved (server-side) to: one.bak 2025/05/04 05:50:37 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dozoqax1kegu/dst': Waiting for transfers to finish 2025/05/04 05:50:38 DEBUG : one: md5 = 32691ffe88e3625037ac740b90b6e115 OK 2025/05/04 05:50:38 INFO : one: Copied (new) 2025/05/04 05:50:38 DEBUG : Waiting for deletions to finish 2025/05/04 05:50:39 INFO : three.txt: Moved (server-side) to: three.txt.bak 2025/05/04 05:50:39 INFO : three.txt: Moved into backup dir 2025/05/04 05:50:40 DEBUG : dst/three.txt: md5 = 764562dbdc61376733197807e0a2a712 OK 2025/05/04 05:50:41 DEBUG : one.bak: Excluded (Path Filter) 2025/05/04 05:50:41 DEBUG : three.txt.bak: Excluded (Path Filter) 2025/05/04 05:50:41 DEBUG : one: Sizes differ (src 5 vs dst 4) 2025/05/04 05:50:41 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/05/04 05:50:41 DEBUG : two: Unchanged skipping 2025/05/04 05:50:41 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dozoqax1kegu/dst': Waiting for checks to finish 2025/05/04 05:50:42 INFO : one.bak: Deleted 2025/05/04 05:50:42 INFO : one: Moved (server-side) to: one.bak 2025/05/04 05:50:42 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dozoqax1kegu/dst': Waiting for transfers to finish 2025/05/04 05:50:44 DEBUG : one: md5 = cc93f047f46c7d424175dddff2f6ba77 OK 2025/05/04 05:50:44 INFO : one: Copied (new) 2025/05/04 05:50:44 DEBUG : Waiting for deletions to finish 2025/05/04 05:50:44 INFO : three.txt.bak: Deleted 2025/05/04 05:50:45 INFO : three.txt: Moved (server-side) to: three.txt.bak 2025/05/04 05:50:45 INFO : three.txt: Moved into backup dir 2025/05/04 05:50:48 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" 2025/05/04 05:50:48 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "sk91qgsqfn0r271r2ehsaoc20c" 2025/05/04 05:50:48 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "qltcak2uaegtmcoa8vijdppbp8" 2025/05/04 05:50:48 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "qltcak2uaegtmcoa8vijdppbp8" 2025/05/04 05:50:48 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "sk91qgsqfn0r271r2ehsaoc20c" 2025/05/04 05:50:48 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k" --- PASS: TestSyncBackupDirSuffixOnly (18.48s) === RUN TestSyncSuffix run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dozoqax1kegu'", Local "Local file system at /tmp/rclone3598271736", Modify Window "1ms" 2025/05/04 05:50:50 DEBUG : dst/one: md5 = ed0903efe7aff53c105c96341fc8ad1a OK 2025/05/04 05:50:52 DEBUG : dst/two: md5 = 09db27b7e9a90bccdb4ed4ad84656635 OK 2025/05/04 05:50:53 DEBUG : dst/three.txt: md5 = 02bca61e00a4298d822832d7d738fe37 OK 2025/05/04 05:50:53 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-dozoqax1kegu/dst" 2025/05/04 05:50:53 DEBUG : Creating backend with remote "TestDrive:crypt/cpul26lr8ek8vhk8j66soansr0gvmba19g0oli717lmu0de2ir60/31u3jie661vd5p8j7rtc3hgbh0" 2025/05/04 05:50:54 DEBUG : one: Sizes differ (src 4 vs dst 3) 2025/05/04 05:50:55 INFO : one: Moved (server-side) to: one.bak 2025/05/04 05:50:56 DEBUG : one: md5 = 70caef651d68cb12c662a50c6ad5889d OK 2025/05/04 05:50:56 INFO : one: Copied (new) 2025/05/04 05:50:57 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/05/04 05:50:57 DEBUG : two: Unchanged skipping 2025/05/04 05:50:57 DEBUG : three.txt: Sizes differ (src 6 vs dst 5) 2025/05/04 05:50:58 INFO : three.txt: Moved (server-side) to: three.txt.bak 2025/05/04 05:50:59 DEBUG : three.txt: md5 = 9d84400c69c134cb0dacb9103359a4e3 OK 2025/05/04 05:50:59 INFO : three.txt: Copied (new) 2025/05/04 05:51:00 DEBUG : one: Sizes differ (src 5 vs dst 4) 2025/05/04 05:51:01 INFO : one.bak: Deleted 2025/05/04 05:51:01 INFO : one: Moved (server-side) to: one.bak 2025/05/04 05:51:03 DEBUG : one: md5 = 58924eb440a3b9bc576aaa5837ea17c6 OK 2025/05/04 05:51:03 INFO : one: Copied (new) 2025/05/04 05:51:03 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/05/04 05:51:03 DEBUG : two: Unchanged skipping 2025/05/04 05:51:03 DEBUG : three.txt: Sizes differ (src 19 vs dst 6) 2025/05/04 05:51:04 INFO : three.txt.bak: Deleted 2025/05/04 05:51:04 INFO : three.txt: Moved (server-side) to: three.txt.bak 2025/05/04 05:51:06 DEBUG : three.txt: md5 = 1a15069c6edd377f1afae97ade06088d OK 2025/05/04 05:51:06 INFO : three.txt: Copied (new) 2025/05/04 05:51:09 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "tr2hj63d80ftlmvm6a952snjcc" 2025/05/04 05:51:09 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" 2025/05/04 05:51:09 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "qltcak2uaegtmcoa8vijdppbp8" 2025/05/04 05:51:09 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "sk91qgsqfn0r271r2ehsaoc20c" 2025/05/04 05:51:09 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k" 2025/05/04 05:51:09 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "sk91qgsqfn0r271r2ehsaoc20c" 2025/05/04 05:51:09 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "qltcak2uaegtmcoa8vijdppbp8" --- PASS: TestSyncSuffix (21.42s) === RUN TestSyncSuffixKeepExtension run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dozoqax1kegu'", Local "Local file system at /tmp/rclone3598271736", Modify Window "1ms" 2025/05/04 05:51:12 DEBUG : dst/one: md5 = eff3bfed6b62cf989f949accacb51b4b OK 2025/05/04 05:51:13 DEBUG : dst/two: md5 = 3c25b7e11200cfb0067f9221a8f0d3f5 OK 2025/05/04 05:51:14 DEBUG : dst/three.txt: md5 = 390c705d22c8ba24617ef81442bc2eed OK 2025/05/04 05:51:15 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-dozoqax1kegu/dst" 2025/05/04 05:51:15 DEBUG : Creating backend with remote "TestDrive:crypt/cpul26lr8ek8vhk8j66soansr0gvmba19g0oli717lmu0de2ir60/31u3jie661vd5p8j7rtc3hgbh0" 2025/05/04 05:51:16 DEBUG : one: Sizes differ (src 4 vs dst 3) 2025/05/04 05:51:17 INFO : one: Moved (server-side) to: one-2019-01-01 2025/05/04 05:51:18 DEBUG : one: md5 = ee79e27cec85f096afbaf1f645a4aec3 OK 2025/05/04 05:51:18 INFO : one: Copied (new) 2025/05/04 05:51:18 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/05/04 05:51:18 DEBUG : two: Unchanged skipping 2025/05/04 05:51:18 DEBUG : three.txt: Sizes differ (src 6 vs dst 5) 2025/05/04 05:51:19 INFO : three.txt: Moved (server-side) to: three-2019-01-01.txt 2025/05/04 05:51:20 DEBUG : three.txt: md5 = 4b73b21d5e1286f1d7ee63698802861b OK 2025/05/04 05:51:20 INFO : three.txt: Copied (new) 2025/05/04 05:51:22 DEBUG : one: Sizes differ (src 5 vs dst 4) 2025/05/04 05:51:22 INFO : one-2019-01-01: Deleted 2025/05/04 05:51:23 INFO : one: Moved (server-side) to: one-2019-01-01 2025/05/04 05:51:24 DEBUG : one: md5 = 9121db2257a067e5c1fd0e118c4ee478 OK 2025/05/04 05:51:24 INFO : one: Copied (new) 2025/05/04 05:51:24 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/05/04 05:51:24 DEBUG : two: Unchanged skipping 2025/05/04 05:51:24 DEBUG : three.txt: Sizes differ (src 19 vs dst 6) 2025/05/04 05:51:25 INFO : three-2019-01-01.txt: Deleted 2025/05/04 05:51:26 INFO : three.txt: Moved (server-side) to: three-2019-01-01.txt 2025/05/04 05:51:27 DEBUG : three.txt: md5 = 21d4da75667e3ec79df2d112de7a529c OK 2025/05/04 05:51:27 INFO : three.txt: Copied (new) 2025/05/04 05:51:30 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" 2025/05/04 05:51:30 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "tr2hj63d80ftlmvm6a952snjcc" 2025/05/04 05:51:30 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "jcjl1bv3ep0v8kt35lqql1co90" 2025/05/04 05:51:30 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "qtq2f6qq4lgpsmj88vb7147qje3prudmtfdtr2342fth58vo9a50" 2025/05/04 05:51:30 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "jcjl1bv3ep0v8kt35lqql1co90" 2025/05/04 05:51:30 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k" 2025/05/04 05:51:30 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "qtq2f6qq4lgpsmj88vb7147qje3prudmtfdtr2342fth58vo9a50" --- PASS: TestSyncSuffixKeepExtension (21.13s) === RUN TestSyncUTFNorm run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dozoqax1kegu'", Local "Local file system at /tmp/rclone3598271736", Modify Window "1ms" 2025/05/04 05:51:32 DEBUG : Testêé: md5 = 4c7204f939fff83f11e4ea9c9c3ef2ae OK 2025/05/04 05:51:33 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dozoqax1kegu': Waiting for checks to finish 2025/05/04 05:51:33 DEBUG : Testêé: Sizes differ (src 14 vs dst 18) 2025/05/04 05:51:33 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dozoqax1kegu': Waiting for transfers to finish 2025/05/04 05:51:34 DEBUG : Testêé: md5 = 0c4fa5c3266f6a538358cbf2be3e69e1 OK 2025/05/04 05:51:34 INFO : Testêé: Copied (replaced existing) to: Testêé 2025/05/04 05:51:34 DEBUG : Waiting for deletions to finish --- PASS: TestSyncUTFNorm (4.04s) === RUN TestSyncImmutable run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dozoqax1kegu'", Local "Local file system at /tmp/rclone3598271736", Modify Window "1ms" 2025/05/04 05:51:35 DEBUG : existing: Need to transfer - File not found at Destination 2025/05/04 05:51:35 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dozoqax1kegu': Waiting for checks to finish 2025/05/04 05:51:35 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dozoqax1kegu': Waiting for transfers to finish 2025/05/04 05:51:37 DEBUG : existing: md5 = 44b5f42fe3ff52e4b68c09cd81ae027b OK 2025/05/04 05:51:37 INFO : existing: Copied (new) 2025/05/04 05:51:37 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dozoqax1kegu'", Local "Local file system at /tmp/rclone3598271736", Modify Window "1ms" 2025/05/04 05:51:37 DEBUG : existing: Sizes differ (src 8 vs dst 6) 2025/05/04 05:51:37 ERROR : existing: Source and destination exist but do not match: immutable file modified 2025/05/04 05:51:37 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dozoqax1kegu': Waiting for checks to finish 2025/05/04 05:51:37 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dozoqax1kegu': Waiting for transfers to finish 2025/05/04 05:51:37 ERROR : Encrypted drive 'TestCryptDrive:rclone-test-dozoqax1kegu': not deleting files as there were IO errors 2025/05/04 05:51:37 ERROR : Encrypted drive 'TestCryptDrive:rclone-test-dozoqax1kegu': not deleting directories as there were IO errors run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dozoqax1kegu'", Local "Local file system at /tmp/rclone3598271736", Modify Window "1ms" --- PASS: TestSyncImmutable (4.47s) === RUN TestSyncIgnoreCase run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dozoqax1kegu'", Local "Local file system at /tmp/rclone3598271736", Modify Window "1ms" 2025/05/04 05:51:41 DEBUG : EXISTING: md5 = b7ecba23c58cff55fa905ce0382ffef2 OK 2025/05/04 05:51:41 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dozoqax1kegu': Waiting for checks to finish 2025/05/04 05:51:41 DEBUG : existing: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/05/04 05:51:41 DEBUG : existing: Unchanged skipping 2025/05/04 05:51:41 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dozoqax1kegu': Waiting for transfers to finish 2025/05/04 05:51:41 DEBUG : Waiting for deletions to finish 2025/05/04 05:51:41 INFO : There was nothing to transfer --- PASS: TestSyncIgnoreCase (3.10s) === RUN TestFixCase run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dozoqax1kegu'", Local "Local file system at /tmp/rclone3598271736", Modify Window "1ms" sync_test.go:2635: Skipping test as local or remote are case-sensitive --- SKIP: TestFixCase (0.42s) === RUN TestMaxTransfer === RUN TestMaxTransfer/Hard run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dozoqax1kegu'", Local "Local file system at /tmp/rclone3598271736", 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-dozoqax1kegu'", Local "Local file system at /tmp/rclone3598271736", 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-dozoqax1kegu'", Local "Local file system at /tmp/rclone3598271736", Modify Window "1ms" sync_test.go:2674: This test only runs on local --- PASS: TestMaxTransfer (1.38s) --- SKIP: TestMaxTransfer/Hard (0.46s) --- SKIP: TestMaxTransfer/Soft (0.47s) --- SKIP: TestMaxTransfer/Cautious (0.46s) === RUN TestSyncConcurrentDelete run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dozoqax1kegu'", Local "Local file system at /tmp/rclone3598271736", Modify Window "1ms" 2025/05/04 05:51:46 DEBUG : both0: md5 = d40871c866a115b3aa2f23e24b04d609 OK 2025/05/04 05:51:47 DEBUG : only0: md5 = 16bef70deee3b64bfd5db15d1e94ebc1 OK 2025/05/04 05:51:48 DEBUG : both1: md5 = 600dfaa2f091d3973050aee1f9c3dc73 OK 2025/05/04 05:51:50 DEBUG : only1: md5 = ecf629b09dc278d60159b6304ccde344 OK 2025/05/04 05:51:51 DEBUG : both2: md5 = f0e71c984cebca37a4d3c87fec6d1d65 OK 2025/05/04 05:51:53 DEBUG : only2: md5 = 3f05e337bc952a9e5fbe121e287b659a OK 2025/05/04 05:51:54 DEBUG : both3: md5 = 492aa9f97fe5bd86ab113367445074a0 OK 2025/05/04 05:51:55 DEBUG : only3: md5 = 52689fa0b071b2f35ee2f68d3031aa1d OK 2025/05/04 05:51:57 DEBUG : both4: md5 = f75d8864dc9d3e729cc3b506e09663be OK 2025/05/04 05:51:58 DEBUG : only4: md5 = 6bbbf5a2258d25392085a15c9cd89dbf OK 2025/05/04 05:51:59 DEBUG : both5: md5 = 281243d887426c334b9bc46e7b3cb958 OK 2025/05/04 05:52:01 DEBUG : only5: md5 = 9901cf20e745d9a1f2df4208c7892eb8 OK 2025/05/04 05:52:02 DEBUG : both6: md5 = e325ab6459a9d92d5badafa10ae416b7 OK 2025/05/04 05:52:03 DEBUG : only6: md5 = be2b01b861f662c5e01a1821a3ac6882 OK 2025/05/04 05:52:05 DEBUG : both7: md5 = 9628d75c183fd7fc69dd0fd2f9f1bd74 OK 2025/05/04 05:52:06 DEBUG : only7: md5 = 43d3823f4ff6b6cbca7a1c1b602c527f OK 2025/05/04 05:52:07 DEBUG : both8: md5 = adaa59b94d7635501596a797b8f3b686 OK 2025/05/04 05:52:09 DEBUG : only8: md5 = 863ceb3c80d16ebbe64fde8a26b16797 OK 2025/05/04 05:52:10 DEBUG : both9: md5 = 32b7903d33a029c0a12739d0ad0f68cc OK 2025/05/04 05:52:11 DEBUG : only9: md5 = f629930d1c76c5a73b114c632779c646 OK 2025/05/04 05:52:12 DEBUG : both10: md5 = a94fd69581b17b2390d3127136eef5b9 OK 2025/05/04 05:52:14 DEBUG : only10: md5 = 82fccd8a24543b4a5d3aa857e680c321 OK 2025/05/04 05:52:15 DEBUG : both11: md5 = 23ebfa06e89a44dc2b1b6ba336967c77 OK 2025/05/04 05:52:16 DEBUG : only11: md5 = 5a6517686e1f07df930f756a80403d7b OK 2025/05/04 05:52:17 DEBUG : both12: md5 = 8a6a3929ddfb65c0b1693ea45cfb1b38 OK 2025/05/04 05:52:19 DEBUG : only12: md5 = 742eb2c7a9fdd9bc7a972bfb70a624b0 OK 2025/05/04 05:52:20 DEBUG : both13: md5 = 8627879eeae8c4390446d7c9152508c3 OK 2025/05/04 05:52:22 DEBUG : only13: md5 = abb2f89c150d43bf6cd312a2ba888e72 OK 2025/05/04 05:52:23 DEBUG : both14: md5 = 0f0bbd9b48e9be43a738ea4bfdec2aa5 OK 2025/05/04 05:52:24 DEBUG : only14: md5 = ad5ee1f966cace27564bd907c88d5a2c OK 2025/05/04 05:52:26 DEBUG : both15: md5 = 935805483c588d7934abacbf3b4677c8 OK 2025/05/04 05:52:27 DEBUG : only15: md5 = 7cf30ccfc0c05c86ab625d64a75941ef OK 2025/05/04 05:52:28 DEBUG : both16: md5 = c7f8d0cfb9d0108579f1d07af798709c OK 2025/05/04 05:52:29 DEBUG : only16: md5 = c22a7cd1f4af70e9830aeb7895bdfc02 OK 2025/05/04 05:52:31 DEBUG : both17: md5 = 62ad9634590374c30bcbfd322d87a967 OK 2025/05/04 05:52:32 DEBUG : only17: md5 = e31aa7da69e636df9932307928fde5ab OK 2025/05/04 05:52:33 DEBUG : both18: md5 = f32f0f67836cd12da9f9f60c5c4f1d77 OK 2025/05/04 05:52:35 DEBUG : only18: md5 = e5a5a167ec0750a157789d820ac5590a OK 2025/05/04 05:52:36 DEBUG : both19: md5 = 603261acfd70c863707328271c681e35 OK 2025/05/04 05:52:37 DEBUG : only19: md5 = 8ae9603f19d752dbcb6838df010569e9 OK 2025/05/04 05:52:38 DEBUG : both1: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/05/04 05:52:38 DEBUG : both10: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/05/04 05:52:38 DEBUG : both11: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/05/04 05:52:38 DEBUG : both0: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/05/04 05:52:38 DEBUG : both1: Unchanged skipping 2025/05/04 05:52:38 DEBUG : both12: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/05/04 05:52:38 DEBUG : both12: Unchanged skipping 2025/05/04 05:52:38 DEBUG : both13: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/05/04 05:52:38 DEBUG : both13: Unchanged skipping 2025/05/04 05:52:38 DEBUG : both14: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/05/04 05:52:38 DEBUG : both14: Unchanged skipping 2025/05/04 05:52:38 DEBUG : both15: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/05/04 05:52:38 DEBUG : both15: Unchanged skipping 2025/05/04 05:52:38 DEBUG : both16: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/05/04 05:52:38 DEBUG : both16: Unchanged skipping 2025/05/04 05:52:38 DEBUG : both17: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/05/04 05:52:38 DEBUG : both17: Unchanged skipping 2025/05/04 05:52:38 DEBUG : both18: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/05/04 05:52:38 DEBUG : both18: Unchanged skipping 2025/05/04 05:52:38 DEBUG : both19: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/05/04 05:52:38 DEBUG : both19: Unchanged skipping 2025/05/04 05:52:38 DEBUG : both2: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/05/04 05:52:38 DEBUG : both2: Unchanged skipping 2025/05/04 05:52:38 DEBUG : both3: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/05/04 05:52:38 DEBUG : both3: Unchanged skipping 2025/05/04 05:52:38 DEBUG : both4: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/05/04 05:52:38 DEBUG : both4: Unchanged skipping 2025/05/04 05:52:38 DEBUG : both5: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/05/04 05:52:38 DEBUG : both5: Unchanged skipping 2025/05/04 05:52:38 DEBUG : both6: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/05/04 05:52:38 DEBUG : both6: Unchanged skipping 2025/05/04 05:52:38 DEBUG : both7: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/05/04 05:52:38 DEBUG : both7: Unchanged skipping 2025/05/04 05:52:38 DEBUG : both8: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/05/04 05:52:38 DEBUG : both8: Unchanged skipping 2025/05/04 05:52:38 DEBUG : both9: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/05/04 05:52:38 DEBUG : both9: Unchanged skipping 2025/05/04 05:52:38 DEBUG : both10: Unchanged skipping 2025/05/04 05:52:38 DEBUG : both11: Unchanged skipping 2025/05/04 05:52:38 DEBUG : both0: Unchanged skipping 2025/05/04 05:52:38 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dozoqax1kegu': Waiting for checks to finish 2025/05/04 05:52:38 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dozoqax1kegu': Waiting for transfers to finish 2025/05/04 05:52:38 DEBUG : Waiting for deletions to finish 2025/05/04 05:52:38 INFO : only6: Deleted 2025/05/04 05:52:38 INFO : only10: Deleted 2025/05/04 05:52:38 INFO : only15: Deleted 2025/05/04 05:52:38 INFO : only4: Deleted 2025/05/04 05:52:39 INFO : only12: Deleted 2025/05/04 05:52:39 INFO : only16: Deleted 2025/05/04 05:52:39 INFO : only5: Deleted 2025/05/04 05:52:39 INFO : only18: Deleted 2025/05/04 05:52:39 INFO : only7: Deleted 2025/05/04 05:52:39 INFO : only8: Deleted 2025/05/04 05:52:39 INFO : only0: Deleted 2025/05/04 05:52:40 INFO : only1: Deleted 2025/05/04 05:52:40 INFO : only17: Deleted 2025/05/04 05:52:40 INFO : only3: Deleted 2025/05/04 05:52:40 INFO : only2: Deleted 2025/05/04 05:52:40 INFO : only11: Deleted 2025/05/04 05:52:40 INFO : only9: Deleted 2025/05/04 05:52:40 INFO : only13: Deleted 2025/05/04 05:52:40 INFO : only14: Deleted 2025/05/04 05:52:40 INFO : only19: Deleted 2025/05/04 05:52:40 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dozoqax1kegu'", Local "Local file system at /tmp/rclone3598271736", Modify Window "1ms" --- PASS: TestSyncConcurrentDelete (65.50s) === RUN TestSyncConcurrentTruncate run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dozoqax1kegu'", Local "Local file system at /tmp/rclone3598271736", Modify Window "1ms" 2025/05/04 05:52:51 DEBUG : both0: md5 = 80f2e106cdc440a17aff766c85185c96 OK 2025/05/04 05:52:52 DEBUG : only0: md5 = 41eaae668cf2eca90f69416986112018 OK 2025/05/04 05:52:53 DEBUG : both1: md5 = c8022f2783aeb25bbae58363d1951516 OK 2025/05/04 05:52:55 DEBUG : only1: md5 = cd2c5de3c09dbeb68b8aa3fbd4aaabee OK 2025/05/04 05:52:56 DEBUG : both2: md5 = f38ad6ba63be5d0020f59e31b187b83d OK 2025/05/04 05:52:57 DEBUG : only2: md5 = 8b650e7a470d179c40589952f1bf803b OK 2025/05/04 05:52:58 DEBUG : both3: md5 = ec4b1df339a7333754ac81302f537656 OK 2025/05/04 05:53:00 DEBUG : only3: md5 = 55786744779687ffc61aca2583adf6a2 OK 2025/05/04 05:53:01 DEBUG : both4: md5 = a4d55fb1d9edc868e0a6e4c217396b4e OK 2025/05/04 05:53:02 DEBUG : only4: md5 = 49cd9a706645b3d42c13ae04708e32a5 OK 2025/05/04 05:53:04 DEBUG : both5: md5 = 66c5363e20017d66ac53e26dae994eec OK 2025/05/04 05:53:05 DEBUG : only5: md5 = 726c1a423039fdd6e963ab338c3959ae OK 2025/05/04 05:53:06 DEBUG : both6: md5 = 3f71fe11478487c668ac5ff5f84389a6 OK 2025/05/04 05:53:07 DEBUG : only6: md5 = 2216fa1d5e8d6086f0b0ae36a1a13c31 OK 2025/05/04 05:53:09 DEBUG : both7: md5 = 713371cdaa8b7b3f811afe4f996e922c OK 2025/05/04 05:53:10 DEBUG : only7: md5 = 38333e0c8bc6fbf2b02370316dae67d6 OK 2025/05/04 05:53:12 DEBUG : both8: md5 = 7972fcdf863881494a9f5a0db25d8e4f OK 2025/05/04 05:53:13 DEBUG : only8: md5 = 2c4851b998b92e36d3caff9a7100f209 OK 2025/05/04 05:53:14 DEBUG : both9: md5 = 52b30a2582a17e3c0b86466d1f95278b OK 2025/05/04 05:53:16 DEBUG : only9: md5 = 084c7365bd4e76108d46330b1f09205a OK 2025/05/04 05:53:17 DEBUG : both10: md5 = 1c34267e5151bf7ef74dea9b1298b666 OK 2025/05/04 05:53:18 DEBUG : only10: md5 = 7b599c648aa52a3b6cfa02b025b063fc OK 2025/05/04 05:53:20 DEBUG : both11: md5 = 8a6f56df2be7a549b1f4ef823f2addd6 OK 2025/05/04 05:53:21 DEBUG : only11: md5 = af2102542c1726b350f372f699957948 OK 2025/05/04 05:53:22 DEBUG : both12: md5 = 3fd2a4e03e70fcf6442c52de94d32dfa OK 2025/05/04 05:53:23 DEBUG : only12: md5 = 3636d9e46a1cab17cf0b24a284517b56 OK 2025/05/04 05:53:25 DEBUG : both13: md5 = 1c7cc241644bbbb77860802186719004 OK 2025/05/04 05:53:26 DEBUG : only13: md5 = 1608c460a1e4425ad646f544083582a6 OK 2025/05/04 05:53:27 DEBUG : both14: md5 = edd36f762be276172ce5a544c368fb6c OK 2025/05/04 05:53:29 DEBUG : only14: md5 = f12375961b552dc45903d519006989a8 OK 2025/05/04 05:53:30 DEBUG : both15: md5 = 3509489586f9bdb8f71d634679ad8bdc OK 2025/05/04 05:53:31 DEBUG : only15: md5 = c8bc6d1c002bfe13ce62a88e785e006e OK 2025/05/04 05:53:32 DEBUG : both16: md5 = 939c006f3c1a5fb60a087042dd47cf56 OK 2025/05/04 05:53:34 DEBUG : only16: md5 = 09bc0c3a7dc308bb66290d8d2893d044 OK 2025/05/04 05:53:35 DEBUG : both17: md5 = fccafe48a0fe3b072797a0feb731933e OK 2025/05/04 05:53:36 DEBUG : only17: md5 = 785f3c5bbafea4e128696ea7dc37f4c2 OK 2025/05/04 05:53:37 DEBUG : both18: md5 = aa2e1b0dece7eece17d3fadef5b7fd11 OK 2025/05/04 05:53:39 DEBUG : only18: md5 = fb24272a5e3c30ac0ee13b9923bb3acd OK 2025/05/04 05:53:40 DEBUG : both19: md5 = a34fd215a85ccb7556404bcd6e359e57 OK 2025/05/04 05:53:41 DEBUG : only19: md5 = 461d2fd8c802be7d892e98978a032b1c OK 2025/05/04 05:53:42 DEBUG : both0: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/05/04 05:53:42 DEBUG : both1: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/05/04 05:53:42 DEBUG : both10: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/05/04 05:53:42 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dozoqax1kegu': Waiting for checks to finish 2025/05/04 05:53:42 DEBUG : both11: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/05/04 05:53:42 DEBUG : both0: Unchanged skipping 2025/05/04 05:53:42 DEBUG : both12: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/05/04 05:53:42 DEBUG : both12: Unchanged skipping 2025/05/04 05:53:42 DEBUG : both13: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/05/04 05:53:42 DEBUG : both13: Unchanged skipping 2025/05/04 05:53:42 DEBUG : both14: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/05/04 05:53:42 DEBUG : both14: Unchanged skipping 2025/05/04 05:53:42 DEBUG : both15: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/05/04 05:53:42 DEBUG : both15: Unchanged skipping 2025/05/04 05:53:42 DEBUG : both16: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/05/04 05:53:42 DEBUG : both16: Unchanged skipping 2025/05/04 05:53:42 DEBUG : both17: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/05/04 05:53:42 DEBUG : both17: Unchanged skipping 2025/05/04 05:53:42 DEBUG : both18: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/05/04 05:53:42 DEBUG : both18: Unchanged skipping 2025/05/04 05:53:42 DEBUG : both19: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/05/04 05:53:42 DEBUG : both19: Unchanged skipping 2025/05/04 05:53:42 DEBUG : both2: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/05/04 05:53:42 DEBUG : both2: Unchanged skipping 2025/05/04 05:53:42 DEBUG : both3: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/05/04 05:53:42 DEBUG : both3: Unchanged skipping 2025/05/04 05:53:42 DEBUG : both4: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/05/04 05:53:42 DEBUG : both4: Unchanged skipping 2025/05/04 05:53:42 DEBUG : both5: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/05/04 05:53:42 DEBUG : both5: Unchanged skipping 2025/05/04 05:53:42 DEBUG : both6: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/05/04 05:53:42 DEBUG : both6: Unchanged skipping 2025/05/04 05:53:42 DEBUG : both7: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/05/04 05:53:42 DEBUG : both7: Unchanged skipping 2025/05/04 05:53:42 DEBUG : both8: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/05/04 05:53:42 DEBUG : both8: Unchanged skipping 2025/05/04 05:53:42 DEBUG : both9: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/05/04 05:53:42 DEBUG : both9: Unchanged skipping 2025/05/04 05:53:42 DEBUG : only0: Sizes differ (src 0 vs dst 6) 2025/05/04 05:53:42 DEBUG : only1: Sizes differ (src 0 vs dst 6) 2025/05/04 05:53:42 DEBUG : only10: Sizes differ (src 0 vs dst 6) 2025/05/04 05:53:42 DEBUG : only11: Sizes differ (src 0 vs dst 6) 2025/05/04 05:53:42 DEBUG : only12: Sizes differ (src 0 vs dst 6) 2025/05/04 05:53:42 DEBUG : only13: Sizes differ (src 0 vs dst 6) 2025/05/04 05:53:42 DEBUG : only14: Sizes differ (src 0 vs dst 6) 2025/05/04 05:53:42 DEBUG : only15: Sizes differ (src 0 vs dst 6) 2025/05/04 05:53:42 DEBUG : only16: Sizes differ (src 0 vs dst 6) 2025/05/04 05:53:42 DEBUG : only17: Sizes differ (src 0 vs dst 6) 2025/05/04 05:53:42 DEBUG : only18: Sizes differ (src 0 vs dst 6) 2025/05/04 05:53:42 DEBUG : only19: Sizes differ (src 0 vs dst 6) 2025/05/04 05:53:42 DEBUG : only2: Sizes differ (src 0 vs dst 6) 2025/05/04 05:53:42 DEBUG : only3: Sizes differ (src 0 vs dst 6) 2025/05/04 05:53:42 DEBUG : only4: Sizes differ (src 0 vs dst 6) 2025/05/04 05:53:42 DEBUG : only5: Sizes differ (src 0 vs dst 6) 2025/05/04 05:53:42 DEBUG : only6: Sizes differ (src 0 vs dst 6) 2025/05/04 05:53:42 DEBUG : only7: Sizes differ (src 0 vs dst 6) 2025/05/04 05:53:42 DEBUG : only8: Sizes differ (src 0 vs dst 6) 2025/05/04 05:53:42 DEBUG : only9: Sizes differ (src 0 vs dst 6) 2025/05/04 05:53:42 DEBUG : both1: Unchanged skipping 2025/05/04 05:53:42 DEBUG : both10: Unchanged skipping 2025/05/04 05:53:42 DEBUG : both11: Unchanged skipping 2025/05/04 05:53:42 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dozoqax1kegu': Waiting for transfers to finish 2025/05/04 05:53:43 DEBUG : only11: md5 = b91eb9ca2a2b87a232d24da9ec1912e7 OK 2025/05/04 05:53:43 INFO : only11: Copied (replaced existing) 2025/05/04 05:53:43 DEBUG : only0: md5 = a5734ccb1f0afdc6930cb34c18a232c2 OK 2025/05/04 05:53:43 INFO : only0: Copied (replaced existing) 2025/05/04 05:53:43 DEBUG : only10: md5 = de15ee49588d996c622be909a8f5054c OK 2025/05/04 05:53:43 INFO : only10: Copied (replaced existing) 2025/05/04 05:53:43 DEBUG : only1: md5 = bac5646e828084b31c03dfc51906d854 OK 2025/05/04 05:53:43 INFO : only1: Copied (replaced existing) 2025/05/04 05:53:44 DEBUG : only12: md5 = ebcdc759cb9a25833a2de19315380010 OK 2025/05/04 05:53:44 INFO : only12: Copied (replaced existing) 2025/05/04 05:53:44 DEBUG : only13: md5 = 45c8e7ac87ff495e8efe5fdc6c101f72 OK 2025/05/04 05:53:44 INFO : only13: Copied (replaced existing) 2025/05/04 05:53:44 DEBUG : only14: md5 = c3483e314585969f9367da99d41d36e6 OK 2025/05/04 05:53:44 INFO : only14: Copied (replaced existing) 2025/05/04 05:53:44 DEBUG : only15: md5 = a19f62f927131868a9905878c946ec21 OK 2025/05/04 05:53:44 INFO : only15: Copied (replaced existing) 2025/05/04 05:53:45 DEBUG : only16: md5 = d14d8061f58f842fb9a5ab8f9572d942 OK 2025/05/04 05:53:45 INFO : only16: Copied (replaced existing) 2025/05/04 05:53:45 DEBUG : only17: md5 = 1bf3ae4ec621478b837faf66f1d11f74 OK 2025/05/04 05:53:45 INFO : only17: Copied (replaced existing) 2025/05/04 05:53:45 DEBUG : only18: md5 = 19d9e08d0b0986987b6a69ce45fa3cd9 OK 2025/05/04 05:53:45 INFO : only18: Copied (replaced existing) 2025/05/04 05:53:45 DEBUG : only19: md5 = 53f581763e70aedd05432edb485a3b0c OK 2025/05/04 05:53:45 INFO : only19: Copied (replaced existing) 2025/05/04 05:53:46 DEBUG : only4: md5 = b3d235276a5cf858eed5cbe3fd3eb952 OK 2025/05/04 05:53:46 INFO : only4: Copied (replaced existing) 2025/05/04 05:53:46 DEBUG : only2: md5 = f36d48f672f659c148ec465be6e77131 OK 2025/05/04 05:53:46 INFO : only2: Copied (replaced existing) 2025/05/04 05:53:46 DEBUG : only5: md5 = 88afe705bad4c136fd9b394468098186 OK 2025/05/04 05:53:46 INFO : only5: Copied (replaced existing) 2025/05/04 05:53:46 DEBUG : only3: md5 = e74c99487513b9a334c1db57a3879db5 OK 2025/05/04 05:53:46 INFO : only3: Copied (replaced existing) 2025/05/04 05:53:47 DEBUG : only6: md5 = 4038e34c2236629633d1d4a1340eb36c OK 2025/05/04 05:53:47 INFO : only6: Copied (replaced existing) 2025/05/04 05:53:47 DEBUG : only7: md5 = 5ed35e8410228e85ff5ea3e3deb6b8f9 OK 2025/05/04 05:53:47 INFO : only7: Copied (replaced existing) 2025/05/04 05:53:47 DEBUG : only8: md5 = cf16dca89f3470c9b6bf355741812864 OK 2025/05/04 05:53:47 INFO : only8: Copied (replaced existing) 2025/05/04 05:53:47 DEBUG : only9: md5 = 1759165ea21e5bb85d55652b5ceb8047 OK 2025/05/04 05:53:47 INFO : only9: Copied (replaced existing) 2025/05/04 05:53:47 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dozoqax1kegu'", Local "Local file system at /tmp/rclone3598271736", Modify Window "1ms" --- PASS: TestSyncConcurrentTruncate (75.59s) === RUN TestSyncReplaceDirModTime run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dozoqax1kegu'", Local "Local file system at /tmp/rclone3598271736", Modify Window "1ms" 2025/05/04 05:54:05 DEBUG : empty_dir: Making directory with metadata 2025/05/04 05:54:05 INFO : empty_dir: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2025/05/04 05:54:05 DEBUG : empty_on_remote: Making directory with metadata 2025/05/04 05:54:05 INFO : empty_on_remote: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2025/05/04 05:54:05 DEBUG : empty_on_remote: Making directory with metadata 2025/05/04 05:54:06 INFO : empty_on_remote: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dozoqax1kegu'", Local "Local file system at /tmp/rclone3598271736", Modify Window "1ms" 2025/05/04 05:54:11 INFO : test_dir1: Set directory modification time (using DirSetModTime) 2025/05/04 05:54:11 INFO : test_dir2: Set directory modification time (using DirSetModTime) 2025/05/04 05:54:11 INFO : test_dir2/sub_dir: Set directory modification time (using DirSetModTime) 2025/05/04 05:54:11 INFO : empty_on_remote: Set directory modification time (using DirSetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dozoqax1kegu'", Local "Local file system at /tmp/rclone3598271736", Modify Window "1ms" 2025/05/04 05:54:18 DEBUG : heqj02jg0dcqlem7gl0500bvp0/24g2k8bseitblkmqnie1ibl2s8: Rmdir: contains trashed file: "633fmaa0qic3kv3cladnu11pto" 2025/05/04 05:54:18 DEBUG : heqj02jg0dcqlem7gl0500bvp0: Rmdir: contains trashed file: "24g2k8bseitblkmqnie1ibl2s8" 2025/05/04 05:54:19 DEBUG : gq68srrpl0nnf394bgf7dbu9kc: Rmdir: contains trashed file: "d26uovf0miqhd1mu3c9jbseq00" --- PASS: TestSyncReplaceDirModTime (15.66s) === RUN TestSyncReplaceDirModTimeWithEmptyDirs run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dozoqax1kegu'", Local "Local file system at /tmp/rclone3598271736", Modify Window "1ms" 2025/05/04 05:54:21 DEBUG : empty_dir: Making directory with metadata 2025/05/04 05:54:21 INFO : empty_dir: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2025/05/04 05:54:21 DEBUG : empty_on_remote: Making directory with metadata 2025/05/04 05:54:21 INFO : empty_on_remote: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2025/05/04 05:54:21 DEBUG : empty_on_remote: Making directory with metadata 2025/05/04 05:54:22 INFO : empty_on_remote: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dozoqax1kegu'", Local "Local file system at /tmp/rclone3598271736", Modify Window "1ms" 2025/05/04 05:54:26 INFO : test_dir1: Set directory modification time (using DirSetModTime) 2025/05/04 05:54:26 INFO : test_dir2: Set directory modification time (using DirSetModTime) 2025/05/04 05:54:26 INFO : test_dir2/sub_dir: Set directory modification time (using DirSetModTime) 2025/05/04 05:54:26 INFO : empty_on_remote: Set directory modification time (using DirSetModTime) 2025/05/04 05:54:26 INFO : empty_dir: Set directory modification time (using DirSetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dozoqax1kegu'", Local "Local file system at /tmp/rclone3598271736", Modify Window "1ms" 2025/05/04 05:54:33 DEBUG : heqj02jg0dcqlem7gl0500bvp0/24g2k8bseitblkmqnie1ibl2s8: Rmdir: contains trashed file: "633fmaa0qic3kv3cladnu11pto" 2025/05/04 05:54:34 DEBUG : heqj02jg0dcqlem7gl0500bvp0: Rmdir: contains trashed file: "24g2k8bseitblkmqnie1ibl2s8" 2025/05/04 05:54:35 DEBUG : gq68srrpl0nnf394bgf7dbu9kc: Rmdir: contains trashed file: "d26uovf0miqhd1mu3c9jbseq00" --- PASS: TestSyncReplaceDirModTimeWithEmptyDirs (16.56s) === RUN TestNothingToTransferWithEmptyDirs run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dozoqax1kegu'", Local "Local file system at /tmp/rclone3598271736", Modify Window "1ms" 2025/05/04 05:54:38 INFO : sub dir: Set directory modification time (using DirSetModTime) 2025/05/04 05:54:38 DEBUG : sub dir: Making directory with metadata 2025/05/04 05:54:38 INFO : sub dir: Made directory with metadata (mtime=2011-12-30T12:59:59Z) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dozoqax1kegu'", Local "Local file system at /tmp/rclone3598271736", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dozoqax1kegu'", Local "Local file system at /tmp/rclone3598271736", Modify Window "1ms" 2025/05/04 05:54:55 INFO : sub dir2: Set directory modification time (using DirSetModTime) 2025/05/04 05:54:55 INFO : sub dir2: Set directory modification time (using DirSetModTime) 2025/05/04 05:54:55 INFO : sub dirEmpty/sub dirEmpty2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2025/05/04 05:54:55 INFO : sub dirEmpty: Set directory modification time (using DirSetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dozoqax1kegu'", Local "Local file system at /tmp/rclone3598271736", Modify Window "1ms" 2025/05/04 05:55:09 DEBUG : gcsdkq814sbtppue42dpsbg8ug: Rmdir: contains trashed file: "sjuo65gk5q3r1199jselk9k9o0" 2025/05/04 05:55:09 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/37qp6d1gohacv723ij3brofbu8/i24n0ln37pa2hv8pctddeuh73o: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" 2025/05/04 05:55:10 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/37qp6d1gohacv723ij3brofbu8: Rmdir: contains trashed file: "i24n0ln37pa2hv8pctddeuh73o" 2025/05/04 05:55:11 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "37qp6d1gohacv723ij3brofbu8" 2025/05/04 05:55:11 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak" 2025/05/04 05:55:12 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak" 2025/05/04 05:55:13 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak" 2025/05/04 05:55:14 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak" 2025/05/04 05:55:14 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/4r13oncfa2rsrr82oqhsqv24ns: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" 2025/05/04 05:55:15 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc: Rmdir: contains trashed file: "4r13oncfa2rsrr82oqhsqv24ns" 2025/05/04 05:55:15 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak" 2025/05/04 05:55:16 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestNothingToTransferWithEmptyDirs (40.02s) === RUN TestNothingToTransferWithoutEmptyDirs run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dozoqax1kegu'", Local "Local file system at /tmp/rclone3598271736", Modify Window "1ms" 2025/05/04 05:55:18 INFO : sub dir: Set directory modification time (using DirSetModTime) 2025/05/04 05:55:18 DEBUG : sub dir: Making directory with metadata 2025/05/04 05:55:18 INFO : sub dir: Made directory with metadata (mtime=2011-12-30T12:59:59Z) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dozoqax1kegu'", Local "Local file system at /tmp/rclone3598271736", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dozoqax1kegu'", Local "Local file system at /tmp/rclone3598271736", Modify Window "1ms" 2025/05/04 05:55:39 INFO : sub dir2: Set directory modification time (using DirSetModTime) 2025/05/04 05:55:39 INFO : sub dir2: Set directory modification time (using DirSetModTime) 2025/05/04 05:55:39 INFO : sub dirEmpty/sub dirEmpty2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2025/05/04 05:55:39 INFO : sub dirEmpty: Set directory modification time (using DirSetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-dozoqax1kegu'", Local "Local file system at /tmp/rclone3598271736", Modify Window "1ms" 2025/05/04 05:55:51 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/37qp6d1gohacv723ij3brofbu8/i24n0ln37pa2hv8pctddeuh73o: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" 2025/05/04 05:55:52 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/37qp6d1gohacv723ij3brofbu8: Rmdir: contains trashed file: "i24n0ln37pa2hv8pctddeuh73o" 2025/05/04 05:55:53 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "37qp6d1gohacv723ij3brofbu8" 2025/05/04 05:55:53 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak" 2025/05/04 05:55:54 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak" 2025/05/04 05:55:55 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak" 2025/05/04 05:55:55 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak" 2025/05/04 05:55:56 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/4r13oncfa2rsrr82oqhsqv24ns: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" 2025/05/04 05:55:57 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc: Rmdir: contains trashed file: "4r13oncfa2rsrr82oqhsqv24ns" 2025/05/04 05:55:57 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak" 2025/05/04 05:55:57 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestNothingToTransferWithoutEmptyDirs (41.67s) PASS 2025/05/04 05:55:59 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dozoqax1kegu': Purge remote "./sync.test -test.v -test.timeout 1h0m0s -remote TestCryptDrive: -verbose -fast-list" - Finished OK in 14m57.990335401s (try 1/5)