"./sync.test -test.v -test.timeout 1h0m0s -remote TestCryptDrive: -verbose -fast-list" - Starting (try 1/5) 2025/04/26 02:20:33 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-datebod4zayo" 2025/04/26 02:20:33 DEBUG : Using config file from "/home/rclone/.rclone.conf" 2025/04/26 02:20:34 DEBUG : Creating backend with remote "TestDrive:crypt/qbp2hfftvuk4chug66bfh86l0s445cogcmp7icnphgefaamfkchg" 2025/04/26 02:20:34 DEBUG : Creating backend with remote "/tmp/rclone381040261" === RUN TestPipe --- PASS: TestPipe (0.00s) === RUN TestPipeConcurrent --- PASS: TestPipeConcurrent (0.04s) === RUN TestPipeOrderBy === RUN TestPipeOrderBy/#00 === RUN TestPipeOrderBy/size === RUN TestPipeOrderBy/name === RUN TestPipeOrderBy/modtime === RUN TestPipeOrderBy/size,ascending === RUN TestPipeOrderBy/name,asc === RUN TestPipeOrderBy/modtime,ascending === RUN TestPipeOrderBy/size,descending === RUN TestPipeOrderBy/name,desc === RUN TestPipeOrderBy/modtime,descending === RUN TestPipeOrderBy/size,mixed,50 === RUN TestPipeOrderBy/size,mixed,51 --- PASS: TestPipeOrderBy (0.00s) --- PASS: TestPipeOrderBy/#00 (0.00s) --- PASS: TestPipeOrderBy/size (0.00s) --- PASS: TestPipeOrderBy/name (0.00s) --- PASS: TestPipeOrderBy/modtime (0.00s) --- PASS: TestPipeOrderBy/size,ascending (0.00s) --- PASS: TestPipeOrderBy/name,asc (0.00s) --- PASS: TestPipeOrderBy/modtime,ascending (0.00s) --- PASS: TestPipeOrderBy/size,descending (0.00s) --- PASS: TestPipeOrderBy/name,desc (0.00s) --- PASS: TestPipeOrderBy/modtime,descending (0.00s) --- PASS: TestPipeOrderBy/size,mixed,50 (0.00s) --- PASS: TestPipeOrderBy/size,mixed,51 (0.00s) === RUN TestNewLess === RUN TestNewLess/blankOK === RUN TestNewLess/tooManyParts === RUN TestNewLess/tooManyParts2 === RUN TestNewLess/badMixed === RUN TestNewLess/unknownComparison === RUN TestNewLess/unknownSortDirection === RUN TestNewLess/size === RUN TestNewLess/name === RUN TestNewLess/modtime === RUN TestNewLess/size,ascending === RUN TestNewLess/name,asc === RUN TestNewLess/modtime,ascending === RUN TestNewLess/size,descending === RUN TestNewLess/name,desc === RUN TestNewLess/modtime,descending === RUN TestNewLess/modtime,mixed === RUN TestNewLess/modtime,mixed,30 --- PASS: TestNewLess (0.00s) --- PASS: TestNewLess/blankOK (0.00s) --- PASS: TestNewLess/tooManyParts (0.00s) --- PASS: TestNewLess/tooManyParts2 (0.00s) --- PASS: TestNewLess/badMixed (0.00s) --- PASS: TestNewLess/unknownComparison (0.00s) --- PASS: TestNewLess/unknownSortDirection (0.00s) --- PASS: TestNewLess/size (0.00s) --- PASS: TestNewLess/name (0.00s) --- PASS: TestNewLess/modtime (0.00s) --- PASS: TestNewLess/size,ascending (0.00s) --- PASS: TestNewLess/name,asc (0.00s) --- PASS: TestNewLess/modtime,ascending (0.00s) --- PASS: TestNewLess/size,descending (0.00s) --- PASS: TestNewLess/name,desc (0.00s) --- PASS: TestNewLess/modtime,descending (0.00s) --- PASS: TestNewLess/modtime,mixed (0.00s) --- PASS: TestNewLess/modtime,mixed,30 (0.00s) === RUN TestRcCopy rc_test.go:16: Skipping test on non local remote --- SKIP: TestRcCopy (0.00s) === RUN TestRcMove rc_test.go:16: Skipping test on non local remote --- SKIP: TestRcMove (0.00s) === RUN TestRcSync rc_test.go:16: Skipping test on non local remote --- SKIP: TestRcSync (0.00s) === RUN TestCopyWithDryRun run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-datebod4zayo'", Local "Local file system at /tmp/rclone381040261", Modify Window "1ms" 2025/04/26 02:20:35 DEBUG : Added delayed dir = "sub dir", newDst= 2025/04/26 02:20:35 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2025/04/26 02:20:35 NOTICE: sub dir/hello world: Skipped copy as --dry-run is set (size 11) 2025/04/26 02:20:35 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-datebod4zayo': Waiting for checks to finish 2025/04/26 02:20:35 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-datebod4zayo': Waiting for transfers to finish 2025/04/26 02:20:35 NOTICE: sub dir: Skipped set directory modification time as --dry-run is set run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-datebod4zayo'", Local "Local file system at /tmp/rclone381040261", Modify Window "1ms" --- PASS: TestCopyWithDryRun (1.83s) === RUN TestCopy run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-datebod4zayo'", Local "Local file system at /tmp/rclone381040261", Modify Window "1ms" 2025/04/26 02:20:36 INFO : sub dir: Set directory modification time (using DirSetModTime) 2025/04/26 02:20:36 DEBUG : Added delayed dir = "sub dir", newDst= 2025/04/26 02:20:36 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2025/04/26 02:20:36 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-datebod4zayo': Waiting for checks to finish 2025/04/26 02:20:36 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-datebod4zayo': Waiting for transfers to finish 2025/04/26 02:20:39 DEBUG : sub dir/hello world: md5 = 0eeff10cee368f4a0d2e5942615b1c5d OK 2025/04/26 02:20:39 INFO : sub dir/hello world: Copied (new) 2025/04/26 02:20:39 INFO : sub dir: Set directory modification time (using DirSetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-datebod4zayo'", Local "Local file system at /tmp/rclone381040261", Modify Window "1ms" 2025/04/26 02:20:41 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestCopy (5.58s) === RUN TestCopyMetadata run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-datebod4zayo'", Local "Local file system at /tmp/rclone381040261", Modify Window "1ms" 2025/04/26 02:20:42 DEBUG : metadata sub dir: Making directory with metadata 2025/04/26 02:20:42 INFO : metadata sub dir: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2025/04/26 02:20:42 DEBUG : empty metadata sub dir: Making directory with metadata 2025/04/26 02:20:42 INFO : empty metadata sub dir: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2025/04/26 02:20:42 DEBUG : Local file system at /tmp/rclone381040261: File to upload is small (21 bytes), uploading instead of streaming 2025/04/26 02:20:42 DEBUG : metadata sub dir/hello metadata world: md5 = baa7a013449dbba2b1ed02b5cfb4e1a2 OK 2025/04/26 02:20:42 DEBUG : metadata sub dir/hello metadata world: Size and md5 of src and dst objects identical 2025/04/26 02:20:42 INFO : metadata sub dir: Set directory modification time (using DirSetModTime) 2025/04/26 02:20:42 DEBUG : Google drive root 'crypt/qbp2hfftvuk4chug66bfh86l0s445cogcmp7icnphgefaamfkchg': Skipping btime metadata as can't update it on an existing file: 2025-04-26T02:20:42.357581387Z 2025/04/26 02:20:43 INFO : empty metadata sub dir: Updated directory metadata 2025/04/26 02:20:43 DEBUG : Google drive root 'crypt/qbp2hfftvuk4chug66bfh86l0s445cogcmp7icnphgefaamfkchg': Skipping btime metadata as can't update it on an existing file: 2025-04-26T02:20:42.357581387Z 2025/04/26 02:20:44 INFO : metadata sub dir: Updated directory metadata 2025/04/26 02:20:44 DEBUG : metadata sub dir/hello metadata world: Need to transfer - File not found at Destination 2025/04/26 02:20:44 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-datebod4zayo': Waiting for checks to finish 2025/04/26 02:20:44 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-datebod4zayo': Waiting for transfers to finish 2025/04/26 02:20:45 DEBUG : metadata sub dir/hello metadata world: md5 = 65ecbcd530e2a180b15b8cd4746c551a OK 2025/04/26 02:20:45 INFO : metadata sub dir/hello metadata world: Copied (new) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-datebod4zayo'", Local "Local file system at /tmp/rclone381040261", Modify Window "1ms" 2025/04/26 02:20:47 DEBUG : fg45q1rm3kh00nmmkk4m6ihmrcnel1p7551kqhjr9bk2gtd2gbf0: Rmdir: contains trashed file: "dmuvulfij81f693ur0f1vvbvq9v6iscp56daas3m51n9li5e3470" --- PASS: TestCopyMetadata (7.05s) === RUN TestCopyMetadataNoEmptyDirs run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-datebod4zayo'", Local "Local file system at /tmp/rclone381040261", Modify Window "1ms" 2025/04/26 02:20:49 DEBUG : metadata sub dir: Making directory with metadata 2025/04/26 02:20:49 INFO : metadata sub dir: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2025/04/26 02:20:49 DEBUG : empty metadata sub dir: Making directory with metadata 2025/04/26 02:20:49 INFO : empty metadata sub dir: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2025/04/26 02:20:49 DEBUG : Local file system at /tmp/rclone381040261: File to upload is small (21 bytes), uploading instead of streaming 2025/04/26 02:20:49 DEBUG : metadata sub dir/hello metadata world: md5 = baa7a013449dbba2b1ed02b5cfb4e1a2 OK 2025/04/26 02:20:49 DEBUG : metadata sub dir/hello metadata world: Size and md5 of src and dst objects identical 2025/04/26 02:20:49 INFO : metadata sub dir: Set directory modification time (using DirSetModTime) 2025/04/26 02:20:49 DEBUG : Added delayed dir = "empty metadata sub dir", newDst= 2025/04/26 02:20:49 DEBUG : Added delayed dir = "metadata sub dir", newDst= 2025/04/26 02:20:49 DEBUG : metadata sub dir/hello metadata world: Need to transfer - File not found at Destination 2025/04/26 02:20:49 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-datebod4zayo': Waiting for checks to finish 2025/04/26 02:20:49 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-datebod4zayo': Waiting for transfers to finish 2025/04/26 02:20:51 DEBUG : metadata sub dir/hello metadata world: md5 = 8e87e0cfddc8cd0141e293ee2b1a3ebb OK 2025/04/26 02:20:51 INFO : metadata sub dir/hello metadata world: Copied (new) 2025/04/26 02:20:51 DEBUG : Google drive root 'crypt/qbp2hfftvuk4chug66bfh86l0s445cogcmp7icnphgefaamfkchg': Skipping btime metadata as can't update it on an existing file: 2025-04-26T02:20:49.413596997Z 2025/04/26 02:20:52 INFO : metadata sub dir: Updated directory metadata run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-datebod4zayo'", Local "Local file system at /tmp/rclone381040261", Modify Window "1ms" 2025/04/26 02:20:54 DEBUG : fg45q1rm3kh00nmmkk4m6ihmrcnel1p7551kqhjr9bk2gtd2gbf0: Rmdir: contains trashed file: "dmuvulfij81f693ur0f1vvbvq9v6iscp56daas3m51n9li5e3470" --- PASS: TestCopyMetadataNoEmptyDirs (6.35s) === RUN TestCopyMissingDirectory run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-datebod4zayo'", Local "Local file system at /tmp/rclone381040261", Modify Window "1ms" 2025/04/26 02:20:55 DEBUG : Creating backend with remote "/non-existing" 2025/04/26 02:20:55 ERROR : Local file system at /non-existing: error reading source root directory: directory not found 2025/04/26 02:20:55 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-datebod4zayo': Waiting for checks to finish 2025/04/26 02:20:55 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-datebod4zayo': Waiting for transfers to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-datebod4zayo'", Local "Local file system at /tmp/rclone381040261", Modify Window "1ms" --- PASS: TestCopyMissingDirectory (1.07s) === RUN TestCopyNoTraverse run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-datebod4zayo'", Local "Local file system at /tmp/rclone381040261", Modify Window "1ms" 2025/04/26 02:20:56 DEBUG : Added delayed dir = "sub dir", newDst= 2025/04/26 02:20:57 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2025/04/26 02:20:57 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-datebod4zayo': Waiting for checks to finish 2025/04/26 02:20:57 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-datebod4zayo': Waiting for transfers to finish 2025/04/26 02:20:59 DEBUG : sub dir/hello world: md5 = 34503dc1ff532b58f614933e386347d1 OK 2025/04/26 02:20:59 INFO : sub dir/hello world: Copied (new) 2025/04/26 02:20:59 INFO : sub dir: Set directory modification time (using DirSetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-datebod4zayo'", Local "Local file system at /tmp/rclone381040261", Modify Window "1ms" 2025/04/26 02:21:00 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestCopyNoTraverse (5.28s) === RUN TestCopyCheckFirst run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-datebod4zayo'", Local "Local file system at /tmp/rclone381040261", Modify Window "1ms" 2025/04/26 02:21:02 INFO : Encrypted drive 'TestCryptDrive:rclone-test-datebod4zayo': Running all checks before starting transfers 2025/04/26 02:21:02 DEBUG : Added delayed dir = "sub dir", newDst= 2025/04/26 02:21:02 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2025/04/26 02:21:02 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-datebod4zayo': Waiting for checks to finish 2025/04/26 02:21:02 INFO : Encrypted drive 'TestCryptDrive:rclone-test-datebod4zayo': Checks finished, now starting transfers 2025/04/26 02:21:02 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-datebod4zayo': Waiting for transfers to finish 2025/04/26 02:21:04 DEBUG : sub dir/hello world: md5 = dcd5ae2bf47cbc31c30482eb7bc11c5d OK 2025/04/26 02:21:04 INFO : sub dir/hello world: Copied (new) 2025/04/26 02:21:04 INFO : sub dir: Set directory modification time (using DirSetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-datebod4zayo'", Local "Local file system at /tmp/rclone381040261", Modify Window "1ms" 2025/04/26 02:21:06 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestCopyCheckFirst (5.23s) === RUN TestSyncNoTraverse run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-datebod4zayo'", Local "Local file system at /tmp/rclone381040261", Modify Window "1ms" 2025/04/26 02:21:07 ERROR : Ignoring --no-traverse with sync 2025/04/26 02:21:07 DEBUG : Added delayed dir = "sub dir", newDst= 2025/04/26 02:21:07 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2025/04/26 02:21:07 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-datebod4zayo': Waiting for checks to finish 2025/04/26 02:21:07 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-datebod4zayo': Waiting for transfers to finish 2025/04/26 02:21:09 DEBUG : sub dir/hello world: md5 = 6e37f6a3f2dbefc1858f523ff100b1d7 OK 2025/04/26 02:21:09 INFO : sub dir/hello world: Copied (new) 2025/04/26 02:21:09 DEBUG : Waiting for deletions to finish 2025/04/26 02:21:10 INFO : sub dir: Set directory modification time (using DirSetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-datebod4zayo'", Local "Local file system at /tmp/rclone381040261", Modify Window "1ms" 2025/04/26 02:21:11 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestSyncNoTraverse (5.34s) === RUN TestCopyWithDepth run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-datebod4zayo'", Local "Local file system at /tmp/rclone381040261", Modify Window "1ms" 2025/04/26 02:21:12 DEBUG : hello world2: Need to transfer - File not found at Destination 2025/04/26 02:21:12 DEBUG : Added delayed dir = "sub dir", newDst= 2025/04/26 02:21:12 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-datebod4zayo': Waiting for checks to finish 2025/04/26 02:21:12 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-datebod4zayo': Waiting for transfers to finish 2025/04/26 02:21:14 DEBUG : hello world2: md5 = 3b6793a3bb8415516bcdbc4f407f121b OK 2025/04/26 02:21:14 INFO : hello world2: Copied (new) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-datebod4zayo'", Local "Local file system at /tmp/rclone381040261", Modify Window "1ms" --- PASS: TestCopyWithDepth (3.27s) === RUN TestCopyWithFilesFrom run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-datebod4zayo'", Local "Local file system at /tmp/rclone381040261", Modify Window "1ms" 2025/04/26 02:21:16 DEBUG : potato2: Need to transfer - File not found at Destination 2025/04/26 02:21:16 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-datebod4zayo': Waiting for checks to finish 2025/04/26 02:21:16 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-datebod4zayo': Waiting for transfers to finish 2025/04/26 02:21:17 DEBUG : potato2: md5 = 30b91afdfd52a0e2c5626d1bbad212aa OK 2025/04/26 02:21:17 INFO : potato2: Copied (new) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-datebod4zayo'", Local "Local file system at /tmp/rclone381040261", Modify Window "1ms" --- PASS: TestCopyWithFilesFrom (3.05s) === RUN TestCopyWithFilesFromAndNoTraverse run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-datebod4zayo'", Local "Local file system at /tmp/rclone381040261", Modify Window "1ms" 2025/04/26 02:21:19 DEBUG : potato2: Need to transfer - File not found at Destination 2025/04/26 02:21:19 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-datebod4zayo': Waiting for checks to finish 2025/04/26 02:21:19 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-datebod4zayo': Waiting for transfers to finish 2025/04/26 02:21:20 DEBUG : potato2: md5 = 2a829f715eebca8176c3f9e7d7561350 OK 2025/04/26 02:21:20 INFO : potato2: Copied (new) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-datebod4zayo'", Local "Local file system at /tmp/rclone381040261", Modify Window "1ms" --- PASS: TestCopyWithFilesFromAndNoTraverse (2.94s) === RUN TestCopyEmptyDirectories run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-datebod4zayo'", Local "Local file system at /tmp/rclone381040261", Modify Window "1ms" 2025/04/26 02:21:21 DEBUG : sub dir2/sub sub dir2: Making directory with metadata 2025/04/26 02:21:21 INFO : sub dir2/sub sub dir2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2025/04/26 02:21:21 INFO : sub dir2: Set directory modification time (using DirSetModTime) 2025/04/26 02:21:21 INFO : sub dir: Set directory modification time (using DirSetModTime) 2025/04/26 02:21:22 DEBUG : sub dir: Making directory with metadata 2025/04/26 02:21:22 INFO : sub dir: Made directory with metadata (mtime=2001-02-03T04:05:06.499999999Z) 2025/04/26 02:21:22 DEBUG : sub dir2: Making directory with metadata 2025/04/26 02:21:23 INFO : sub dir2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2025/04/26 02:21:23 DEBUG : sub dir2/sub sub dir2: Making directory with metadata 2025/04/26 02:21:23 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2025/04/26 02:21:24 INFO : sub dir2/sub sub dir2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2025/04/26 02:21:24 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-datebod4zayo': Waiting for checks to finish 2025/04/26 02:21:24 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-datebod4zayo': Waiting for transfers to finish 2025/04/26 02:21:24 DEBUG : sub dir/hello world: md5 = c5f9210efbf5d5763a3f1c14c3ac298f OK 2025/04/26 02:21:24 INFO : sub dir/hello world: Copied (new) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-datebod4zayo'", Local "Local file system at /tmp/rclone381040261", Modify Window "1ms" 2025/04/26 02:21:28 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc: Rmdir: contains trashed file: "cv6a9uf28ngrajena8kt5ijjn0" 2025/04/26 02:21:28 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestCopyEmptyDirectories (7.99s) === RUN TestCopyNoEmptyDirectories run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-datebod4zayo'", Local "Local file system at /tmp/rclone381040261", Modify Window "1ms" 2025/04/26 02:21:29 INFO : sub dir2: Making directory 2025/04/26 02:21:29 DEBUG : sub dir2/sub sub dir2: Making directory with metadata 2025/04/26 02:21:29 INFO : sub dir2/sub sub dir2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2025/04/26 02:21:30 DEBUG : Added delayed dir = "sub dir", newDst= 2025/04/26 02:21:30 DEBUG : Added delayed dir = "sub dir2", newDst= 2025/04/26 02:21:30 DEBUG : Added delayed dir = "sub dir2/sub sub dir2", newDst= 2025/04/26 02:21:30 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2025/04/26 02:21:30 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-datebod4zayo': Waiting for checks to finish 2025/04/26 02:21:30 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-datebod4zayo': Waiting for transfers to finish 2025/04/26 02:21:32 DEBUG : sub dir/hello world: md5 = 10c62d64bd08d7eff670a9b3c9e7f267 OK 2025/04/26 02:21:32 INFO : sub dir/hello world: Copied (new) 2025/04/26 02:21:32 INFO : sub dir: Set directory modification time (using DirSetModTime) 2025/04/26 02:21:34 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestCopyNoEmptyDirectories (4.78s) === RUN TestMoveEmptyDirectories run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-datebod4zayo'", Local "Local file system at /tmp/rclone381040261", Modify Window "1ms" 2025/04/26 02:21:34 DEBUG : sub dir2: Making directory with metadata 2025/04/26 02:21:34 INFO : sub dir2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2025/04/26 02:21:34 DEBUG : sub dir: Making directory with metadata 2025/04/26 02:21:35 INFO : sub dir: Made directory with metadata (mtime=2025-04-26T02:21:34.705696287Z) 2025/04/26 02:21:35 DEBUG : sub dir2: Making directory with metadata 2025/04/26 02:21:36 INFO : sub dir2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2025/04/26 02:21:36 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2025/04/26 02:21:36 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-datebod4zayo': Waiting for checks to finish 2025/04/26 02:21:36 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-datebod4zayo': Waiting for transfers to finish 2025/04/26 02:21:37 DEBUG : sub dir/hello world: md5 = 07b019dfc5cd3e06f9347921e74cb182 OK 2025/04/26 02:21:37 INFO : sub dir/hello world: Copied (new) 2025/04/26 02:21:37 INFO : sub dir/hello world: Deleted run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-datebod4zayo'", Local "Local file system at /tmp/rclone381040261", Modify Window "1ms" 2025/04/26 02:21:40 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestMoveEmptyDirectories (6.86s) === RUN TestSyncNoUpdateDirModtime run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-datebod4zayo'", Local "Local file system at /tmp/rclone381040261", Modify Window "1ms" 2025/04/26 02:21:41 DEBUG : sub dir no update dir modtime: Making directory with metadata 2025/04/26 02:21:41 INFO : sub dir no update dir modtime: Made directory with metadata (mtime=2001-02-03T04:05:06.499999999Z) 2025/04/26 02:21:41 DEBUG : Config file has changed externally - reloading 2025/04/26 02:21:41 DEBUG : TestDrive: Loaded fresh token from config file 2025/04/26 02:21:42 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-datebod4zayo': Waiting for checks to finish 2025/04/26 02:21:42 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-datebod4zayo': Waiting for transfers to finish 2025/04/26 02:21:42 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-datebod4zayo'", Local "Local file system at /tmp/rclone381040261", Modify Window "1ms" --- PASS: TestSyncNoUpdateDirModtime (3.64s) === RUN TestMoveNoEmptyDirectories run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-datebod4zayo'", Local "Local file system at /tmp/rclone381040261", Modify Window "1ms" 2025/04/26 02:21:45 INFO : sub dir2: Making directory 2025/04/26 02:21:45 DEBUG : Added delayed dir = "sub dir", newDst= 2025/04/26 02:21:45 DEBUG : Added delayed dir = "sub dir2", newDst= 2025/04/26 02:21:45 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2025/04/26 02:21:45 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-datebod4zayo': Waiting for checks to finish 2025/04/26 02:21:45 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-datebod4zayo': Waiting for transfers to finish 2025/04/26 02:21:47 DEBUG : sub dir/hello world: md5 = 7f663e76b9533c4da173f9d891b03dd2 OK 2025/04/26 02:21:47 INFO : sub dir/hello world: Copied (new) 2025/04/26 02:21:47 INFO : sub dir/hello world: Deleted 2025/04/26 02:21:48 INFO : sub dir: Set directory modification time (using DirSetModTime) 2025/04/26 02:21:49 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestMoveNoEmptyDirectories (5.12s) === RUN TestSyncEmptyDirectories run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-datebod4zayo'", Local "Local file system at /tmp/rclone381040261", Modify Window "1ms" 2025/04/26 02:21:50 DEBUG : sub dir2: Making directory with metadata 2025/04/26 02:21:50 INFO : sub dir2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2025/04/26 02:21:50 INFO : sub dir: Set directory modification time (using DirSetModTime) 2025/04/26 02:21:50 DEBUG : sub dir: Making directory with metadata 2025/04/26 02:21:51 INFO : sub dir: Made directory with metadata (mtime=2001-02-03T04:05:06.499999999Z) 2025/04/26 02:21:51 DEBUG : sub dir2: Making directory with metadata 2025/04/26 02:21:51 INFO : sub dir2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2025/04/26 02:21:51 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2025/04/26 02:21:51 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-datebod4zayo': Waiting for checks to finish 2025/04/26 02:21:51 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-datebod4zayo': Waiting for transfers to finish 2025/04/26 02:21:53 DEBUG : sub dir/hello world: md5 = 882fc72a07c21fdd4f4a8099744f02b8 OK 2025/04/26 02:21:53 INFO : sub dir/hello world: Copied (new) 2025/04/26 02:21:53 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-datebod4zayo'", Local "Local file system at /tmp/rclone381040261", Modify Window "1ms" 2025/04/26 02:21:55 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestSyncEmptyDirectories (6.52s) === RUN TestSyncSetDelayedModTimes run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-datebod4zayo'", Local "Local file system at /tmp/rclone381040261", Modify Window "1ms" sync_test.go:507: Backend doesn't have DirModTimeUpdatesOnWrite set --- SKIP: TestSyncSetDelayedModTimes (0.45s) === RUN TestSyncNoEmptyDirectories run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-datebod4zayo'", Local "Local file system at /tmp/rclone381040261", Modify Window "1ms" 2025/04/26 02:21:57 INFO : sub dir2: Making directory 2025/04/26 02:21:57 DEBUG : Added delayed dir = "sub dir", newDst= 2025/04/26 02:21:57 DEBUG : Added delayed dir = "sub dir2", newDst= 2025/04/26 02:21:57 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2025/04/26 02:21:57 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-datebod4zayo': Waiting for checks to finish 2025/04/26 02:21:57 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-datebod4zayo': Waiting for transfers to finish 2025/04/26 02:21:59 DEBUG : sub dir/hello world: md5 = f09ff175a20b57bf10ee1a12a0cf4706 OK 2025/04/26 02:21:59 INFO : sub dir/hello world: Copied (new) 2025/04/26 02:21:59 DEBUG : Waiting for deletions to finish 2025/04/26 02:21:59 INFO : sub dir: Set directory modification time (using DirSetModTime) 2025/04/26 02:22:01 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestSyncNoEmptyDirectories (4.80s) === RUN TestServerSideCopy run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-datebod4zayo'", Local "Local file system at /tmp/rclone381040261", Modify Window "1ms" 2025/04/26 02:22:04 DEBUG : sub dir/hello world: md5 = 2bdbdb089010f55af0c7e1665820512f OK 2025/04/26 02:22:04 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-yofutap1mefa" 2025/04/26 02:22:04 DEBUG : Creating backend with remote "TestDrive:crypt/a1t07ue74vmh6ig8to18o88ddv4908dempc3ugkm8l5ku92hv02g" sync_test.go:590: Server side copy (if possible) Encrypted drive 'TestCryptDrive:rclone-test-datebod4zayo' -> Encrypted drive 'TestCryptDrive:rclone-test-yofutap1mefa' 2025/04/26 02:22:05 DEBUG : Added delayed dir = "sub dir", newDst= 2025/04/26 02:22:05 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2025/04/26 02:22:05 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yofutap1mefa': Waiting for checks to finish 2025/04/26 02:22:05 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yofutap1mefa': Waiting for transfers to finish 2025/04/26 02:22:08 INFO : sub dir/hello world: Copied (server-side copy) 2025/04/26 02:22:08 INFO : sub dir: Set directory modification time (using DirSetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-datebod4zayo'", Local "Local file system at /tmp/rclone381040261", Modify Window "1ms" 2025/04/26 02:22:09 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yofutap1mefa': Purge remote 2025/04/26 02:22:10 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestServerSideCopy (9.67s) === RUN TestCopyOverSelf run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-datebod4zayo'", Local "Local file system at /tmp/rclone381040261", Modify Window "1ms" 2025/04/26 02:22:13 DEBUG : sub dir/hello world: md5 = 14b454a1ede45dc28a8a12494efb5a72 OK 2025/04/26 02:22:15 INFO : sub dir: Set directory modification time (using SetModTime) 2025/04/26 02:22:15 DEBUG : Added delayed dir = "sub dir", newDst=sub dir 2025/04/26 02:22:15 DEBUG : sub dir/hello world: Sizes differ (src 17 vs dst 11) 2025/04/26 02:22:15 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-datebod4zayo': Waiting for checks to finish 2025/04/26 02:22:15 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-datebod4zayo': Waiting for transfers to finish 2025/04/26 02:22:16 DEBUG : sub dir/hello world: md5 = 559a269da80ca72c7b55fae6711c65e9 OK 2025/04/26 02:22:16 INFO : sub dir/hello world: Copied (replaced existing) 2025/04/26 02:22:16 INFO : sub dir: Set directory modification time (using SetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-datebod4zayo'", Local "Local file system at /tmp/rclone381040261", Modify Window "1ms" 2025/04/26 02:22:18 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestCopyOverSelf (7.42s) === RUN TestServerSideCopyOverSelf run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-datebod4zayo'", Local "Local file system at /tmp/rclone381040261", Modify Window "1ms" 2025/04/26 02:22:21 DEBUG : sub dir/hello world: md5 = 35637733b739e218d1c1e96a16699c14 OK 2025/04/26 02:22:21 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-huwiley2woli" 2025/04/26 02:22:21 DEBUG : Creating backend with remote "TestDrive:crypt/bsojblkgrmrl8k38v9vj32o1l69khukv53169umbnirm80u1d3f0" sync_test.go:626: Server side copy (if possible) Encrypted drive 'TestCryptDrive:rclone-test-datebod4zayo' -> Encrypted drive 'TestCryptDrive:rclone-test-huwiley2woli' 2025/04/26 02:22:22 DEBUG : Added delayed dir = "sub dir", newDst= 2025/04/26 02:22:22 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2025/04/26 02:22:22 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-huwiley2woli': Waiting for checks to finish 2025/04/26 02:22:22 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-huwiley2woli': Waiting for transfers to finish 2025/04/26 02:22:25 INFO : sub dir/hello world: Copied (server-side copy) 2025/04/26 02:22:25 INFO : sub dir: Set directory modification time (using DirSetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-datebod4zayo'", Local "Local file system at /tmp/rclone381040261", Modify Window "1ms" 2025/04/26 02:22:27 DEBUG : sub dir/hello world: md5 = 50000e73fc364f4950cd058a59e4a060 OK 2025/04/26 02:22:28 DEBUG : sub dir: Directory modification time the same (differ by 0s, within tolerance 1ms) 2025/04/26 02:22:28 DEBUG : Added delayed dir = "sub dir", newDst=sub dir 2025/04/26 02:22:28 DEBUG : sub dir/hello world: Sizes differ (src 17 vs dst 11) 2025/04/26 02:22:28 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-huwiley2woli': Waiting for checks to finish 2025/04/26 02:22:28 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-huwiley2woli': Waiting for transfers to finish 2025/04/26 02:22:29 INFO : sub dir/hello world: Copied (server-side copy) 2025/04/26 02:22:30 INFO : sub dir: Set directory modification time (using SetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-datebod4zayo'", Local "Local file system at /tmp/rclone381040261", Modify Window "1ms" 2025/04/26 02:22:30 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-huwiley2woli': Purge remote 2025/04/26 02:22:31 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestServerSideCopyOverSelf (14.15s) === RUN TestMoveOverSelf run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-datebod4zayo'", Local "Local file system at /tmp/rclone381040261", Modify Window "1ms" 2025/04/26 02:22:35 DEBUG : sub dir/hello world: md5 = b9ac85efdb0f9d4f781d42dc29111ef7 OK 2025/04/26 02:22:36 INFO : sub dir: Set directory modification time (using SetModTime) 2025/04/26 02:22:36 DEBUG : Added delayed dir = "sub dir", newDst=sub dir 2025/04/26 02:22:36 DEBUG : sub dir/hello world: Sizes differ (src 17 vs dst 11) 2025/04/26 02:22:36 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-datebod4zayo': Waiting for checks to finish 2025/04/26 02:22:36 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-datebod4zayo': Waiting for transfers to finish 2025/04/26 02:22:37 DEBUG : sub dir/hello world: md5 = 36aa00c73b8b957ec5b9ba8c88649c45 OK 2025/04/26 02:22:37 INFO : sub dir/hello world: Copied (replaced existing) 2025/04/26 02:22:37 INFO : sub dir/hello world: Deleted 2025/04/26 02:22:38 INFO : sub dir: Set directory modification time (using SetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-datebod4zayo'", Local "Local file system at /tmp/rclone381040261", Modify Window "1ms" 2025/04/26 02:22:39 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestMoveOverSelf (7.47s) === RUN TestServerSideMoveOverSelf run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-datebod4zayo'", Local "Local file system at /tmp/rclone381040261", Modify Window "1ms" 2025/04/26 02:22:42 DEBUG : sub dir/hello world: md5 = 575bdc7553f07cd5bd219e90016078c1 OK 2025/04/26 02:22:43 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-zapevex6qemi" 2025/04/26 02:22:43 DEBUG : Creating backend with remote "TestDrive:crypt/7a3fqgu7l9q5gudu51tgav866tmp8pojl7ddk04nfkbdcoqn8qsg" sync_test.go:671: Server side copy (if possible) Encrypted drive 'TestCryptDrive:rclone-test-datebod4zayo' -> Encrypted drive 'TestCryptDrive:rclone-test-zapevex6qemi' 2025/04/26 02:22:44 DEBUG : Added delayed dir = "sub dir", newDst= 2025/04/26 02:22:44 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2025/04/26 02:22:44 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zapevex6qemi': Waiting for checks to finish 2025/04/26 02:22:44 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zapevex6qemi': Waiting for transfers to finish 2025/04/26 02:22:46 INFO : sub dir/hello world: Copied (server-side copy) 2025/04/26 02:22:47 INFO : sub dir: Set directory modification time (using DirSetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-datebod4zayo'", Local "Local file system at /tmp/rclone381040261", Modify Window "1ms" 2025/04/26 02:22:48 DEBUG : sub dir/hello world: md5 = a42a6cc95897f24b87a988d84e8a8dcd OK 2025/04/26 02:22:49 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zapevex6qemi': Using server-side directory move 2025/04/26 02:22:49 INFO : Encrypted drive 'TestCryptDrive:rclone-test-zapevex6qemi': Server side directory move failed - fallback to file moves: can't copy directory - destination already exists 2025/04/26 02:22:49 DEBUG : sub dir: Directory modification time the same (differ by 0s, within tolerance 1ms) 2025/04/26 02:22:49 DEBUG : Added delayed dir = "sub dir", newDst=sub dir 2025/04/26 02:22:49 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zapevex6qemi': Waiting for checks to finish 2025/04/26 02:22:49 DEBUG : sub dir/hello world: Sizes differ (src 17 vs dst 11) 2025/04/26 02:22:49 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zapevex6qemi': Waiting for transfers to finish 2025/04/26 02:22:50 INFO : sub dir/hello world: Deleted 2025/04/26 02:22:50 INFO : sub dir/hello world: Moved (server-side) 2025/04/26 02:22:51 INFO : sub dir: Set directory modification time (using SetModTime) 2025/04/26 02:22:53 DEBUG : sub dir/hello world: md5 = e6a844464d6451d1a6efef4060181467 OK 2025/04/26 02:22:53 DEBUG : testing file moves 2025/04/26 02:22:54 DEBUG : sub dir: Directory modification time the same (differ by 0s, within tolerance 1ms) 2025/04/26 02:22:54 DEBUG : Added delayed dir = "sub dir", newDst=sub dir 2025/04/26 02:22:54 DEBUG : sub dir/hello world: Sizes differ (src 24 vs dst 17) 2025/04/26 02:22:54 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zapevex6qemi': Waiting for checks to finish 2025/04/26 02:22:54 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zapevex6qemi': Waiting for transfers to finish 2025/04/26 02:22:54 INFO : sub dir/hello world: Deleted 2025/04/26 02:22:55 INFO : sub dir/hello world: Moved (server-side) 2025/04/26 02:22:55 INFO : sub dir: Set directory modification time (using SetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-datebod4zayo'", Local "Local file system at /tmp/rclone381040261", Modify Window "1ms" 2025/04/26 02:22:56 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-zapevex6qemi': Purge remote --- PASS: TestServerSideMoveOverSelf (18.41s) === RUN TestCopyAfterDelete run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-datebod4zayo'", Local "Local file system at /tmp/rclone381040261", Modify Window "1ms" 2025/04/26 02:23:01 DEBUG : sub dir/hello world: md5 = 82e0eefcd308b48b929e37d3312d6897 OK 2025/04/26 02:23:01 ERROR : : error listing: directory not found 2025/04/26 02:23:01 INFO : Local file system at /tmp/rclone381040261: Making directory 2025/04/26 02:23:02 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-datebod4zayo': Waiting for checks to finish 2025/04/26 02:23:02 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-datebod4zayo': Waiting for transfers to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-datebod4zayo'", Local "Local file system at /tmp/rclone381040261", Modify Window "1ms" 2025/04/26 02:23:03 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestCopyAfterDelete (5.64s) === RUN TestCopyRedownload run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-datebod4zayo'", Local "Local file system at /tmp/rclone381040261", Modify Window "1ms" 2025/04/26 02:23:06 DEBUG : sub dir/hello world: md5 = 1104d5a1bb8fafff98120bb394abbc60 OK 2025/04/26 02:23:07 DEBUG : Added delayed dir = "sub dir", newDst= 2025/04/26 02:23:07 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2025/04/26 02:23:07 DEBUG : Local file system at /tmp/rclone381040261: Waiting for checks to finish 2025/04/26 02:23:07 DEBUG : Local file system at /tmp/rclone381040261: Waiting for transfers to finish 2025/04/26 02:23:08 DEBUG : sub dir/hello world.285f0a30.partial: renamed to: sub dir/hello world 2025/04/26 02:23:08 INFO : sub dir/hello world: Copied (new) 2025/04/26 02:23:08 INFO : sub dir: Set directory modification time (using DirSetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-datebod4zayo'", Local "Local file system at /tmp/rclone381040261", Modify Window "1ms" 2025/04/26 02:23:09 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestCopyRedownload (5.74s) === RUN TestSyncBasedOnCheckSum run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-datebod4zayo'", Local "Local file system at /tmp/rclone381040261", Modify Window "1ms" 2025/04/26 02:23:10 DEBUG : check sum: Need to transfer - File not found at Destination 2025/04/26 02:23:10 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-datebod4zayo': Waiting for checks to finish 2025/04/26 02:23:10 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-datebod4zayo': Waiting for transfers to finish 2025/04/26 02:23:12 DEBUG : check sum: md5 = fb28db65bd7d2996142324af0cd35368 OK 2025/04/26 02:23:12 INFO : check sum: Copied (new) 2025/04/26 02:23:12 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-datebod4zayo'", Local "Local file system at /tmp/rclone381040261", Modify Window "1ms" 2025/04/26 02:23:12 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-datebod4zayo': Waiting for checks to finish 2025/04/26 02:23:12 NOTICE: Encrypted drive 'TestCryptDrive:rclone-test-datebod4zayo': --checksum is in use but the source and destination have no hashes in common; falling back to --size-only 2025/04/26 02:23:12 DEBUG : check sum: Size of src and dst objects identical 2025/04/26 02:23:12 DEBUG : check sum: Unchanged skipping 2025/04/26 02:23:12 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-datebod4zayo': Waiting for transfers to finish 2025/04/26 02:23:12 DEBUG : Waiting for deletions to finish 2025/04/26 02:23:12 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-datebod4zayo'", Local "Local file system at /tmp/rclone381040261", Modify Window "1ms" --- PASS: TestSyncBasedOnCheckSum (3.98s) === RUN TestSyncSizeOnly run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-datebod4zayo'", Local "Local file system at /tmp/rclone381040261", Modify Window "1ms" 2025/04/26 02:23:14 DEBUG : sizeonly: Need to transfer - File not found at Destination 2025/04/26 02:23:14 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-datebod4zayo': Waiting for checks to finish 2025/04/26 02:23:14 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-datebod4zayo': Waiting for transfers to finish 2025/04/26 02:23:15 DEBUG : sizeonly: md5 = 8f6ee21e5a0078cc49c28cc90ccccb06 OK 2025/04/26 02:23:15 INFO : sizeonly: Copied (new) 2025/04/26 02:23:15 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-datebod4zayo'", Local "Local file system at /tmp/rclone381040261", Modify Window "1ms" 2025/04/26 02:23:16 DEBUG : sizeonly: Sizes identical 2025/04/26 02:23:16 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-datebod4zayo': Waiting for checks to finish 2025/04/26 02:23:16 DEBUG : sizeonly: Unchanged skipping 2025/04/26 02:23:16 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-datebod4zayo': Waiting for transfers to finish 2025/04/26 02:23:16 DEBUG : Waiting for deletions to finish 2025/04/26 02:23:16 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-datebod4zayo'", Local "Local file system at /tmp/rclone381040261", Modify Window "1ms" --- PASS: TestSyncSizeOnly (3.72s) === RUN TestSyncIgnoreSize run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-datebod4zayo'", Local "Local file system at /tmp/rclone381040261", Modify Window "1ms" 2025/04/26 02:23:18 DEBUG : ignore-size: Need to transfer - File not found at Destination 2025/04/26 02:23:18 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-datebod4zayo': Waiting for checks to finish 2025/04/26 02:23:18 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-datebod4zayo': Waiting for transfers to finish 2025/04/26 02:23:19 DEBUG : ignore-size: md5 = 437a6f5fd48d66d0e5562592d3fcf574 OK 2025/04/26 02:23:19 INFO : ignore-size: Copied (new) 2025/04/26 02:23:19 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-datebod4zayo'", Local "Local file system at /tmp/rclone381040261", Modify Window "1ms" 2025/04/26 02:23:20 DEBUG : ignore-size: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/26 02:23:20 DEBUG : ignore-size: Unchanged skipping 2025/04/26 02:23:20 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-datebod4zayo': Waiting for checks to finish 2025/04/26 02:23:20 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-datebod4zayo': Waiting for transfers to finish 2025/04/26 02:23:20 DEBUG : Waiting for deletions to finish 2025/04/26 02:23:20 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-datebod4zayo'", Local "Local file system at /tmp/rclone381040261", Modify Window "1ms" --- PASS: TestSyncIgnoreSize (3.83s) === RUN TestSyncIgnoreTimes run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-datebod4zayo'", Local "Local file system at /tmp/rclone381040261", Modify Window "1ms" 2025/04/26 02:23:23 DEBUG : existing: md5 = c51b7d7fac579d6a236e95970f1f496b OK 2025/04/26 02:23:23 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-datebod4zayo': Waiting for checks to finish 2025/04/26 02:23:23 DEBUG : existing: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/26 02:23:23 DEBUG : existing: Unchanged skipping 2025/04/26 02:23:23 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-datebod4zayo': Waiting for transfers to finish 2025/04/26 02:23:23 DEBUG : Waiting for deletions to finish 2025/04/26 02:23:23 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-datebod4zayo'", Local "Local file system at /tmp/rclone381040261", Modify Window "1ms" 2025/04/26 02:23:24 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-datebod4zayo': Waiting for checks to finish 2025/04/26 02:23:24 DEBUG : existing: Transferring unconditionally as --ignore-times is in use 2025/04/26 02:23:24 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-datebod4zayo': Waiting for transfers to finish 2025/04/26 02:23:25 DEBUG : existing: md5 = 85f0aa5e01bdb4e72d658f4ee10543ea OK 2025/04/26 02:23:25 INFO : existing: Copied (replaced existing) 2025/04/26 02:23:25 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-datebod4zayo'", Local "Local file system at /tmp/rclone381040261", Modify Window "1ms" --- PASS: TestSyncIgnoreTimes (4.78s) === RUN TestSyncIgnoreExisting run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-datebod4zayo'", Local "Local file system at /tmp/rclone381040261", Modify Window "1ms" 2025/04/26 02:23:27 DEBUG : existing: Need to transfer - File not found at Destination 2025/04/26 02:23:27 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-datebod4zayo': Waiting for checks to finish 2025/04/26 02:23:27 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-datebod4zayo': Waiting for transfers to finish 2025/04/26 02:23:28 DEBUG : existing: md5 = dade2f304877876802b3c75836362018 OK 2025/04/26 02:23:28 INFO : existing: Copied (new) 2025/04/26 02:23:28 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-datebod4zayo'", Local "Local file system at /tmp/rclone381040261", Modify Window "1ms" 2025/04/26 02:23:28 DEBUG : existing: Destination exists, skipping 2025/04/26 02:23:28 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-datebod4zayo': Waiting for checks to finish 2025/04/26 02:23:28 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-datebod4zayo': Waiting for transfers to finish 2025/04/26 02:23:28 DEBUG : Waiting for deletions to finish 2025/04/26 02:23:28 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-datebod4zayo'", Local "Local file system at /tmp/rclone381040261", Modify Window "1ms" --- PASS: TestSyncIgnoreExisting (3.79s) === RUN TestSyncIgnoreErrors run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-datebod4zayo'", Local "Local file system at /tmp/rclone381040261", Modify Window "1ms" 2025/04/26 02:23:32 DEBUG : b/potato: md5 = f6d358a1a1036af14ed1e230c93e6d49 OK 2025/04/26 02:23:34 DEBUG : c/non empty space: md5 = 416963f9ed91b9deaa2ba5d7342de5d1 OK 2025/04/26 02:23:34 INFO : d: Making directory 2025/04/26 02:23:36 DEBUG : Added delayed dir = "a", newDst= 2025/04/26 02:23:36 INFO : c: Set directory modification time (using SetModTime) 2025/04/26 02:23:36 DEBUG : Added delayed dir = "c", newDst=c 2025/04/26 02:23:36 DEBUG : c/non empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/04/26 02:23:36 DEBUG : c/non empty space: Unchanged skipping 2025/04/26 02:23:36 DEBUG : a/potato2: Need to transfer - File not found at Destination 2025/04/26 02:23:36 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-datebod4zayo': Waiting for checks to finish 2025/04/26 02:23:36 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-datebod4zayo': Waiting for transfers to finish 2025/04/26 02:23:38 DEBUG : a/potato2: md5 = a44590c9843b7124a7a81e573b76eda4 OK 2025/04/26 02:23:38 INFO : a/potato2: Copied (new) 2025/04/26 02:23:38 DEBUG : Waiting for deletions to finish 2025/04/26 02:23:39 INFO : b/potato: Deleted 2025/04/26 02:23:39 INFO : a: Set directory modification time (using DirSetModTime) 2025/04/26 02:23:39 INFO : d: Removing directory 2025/04/26 02:23:40 INFO : b: Removing directory 2025/04/26 02:23:40 DEBUG : 32d8ua6196mc1r7qkfog53rkg0: Rmdir: contains trashed file: "2m507n64kafsi59v9q71r281a4" 2025/04/26 02:23:40 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-datebod4zayo': deleted 2 directories run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-datebod4zayo'", Local "Local file system at /tmp/rclone381040261", Modify Window "1ms" 2025/04/26 02:23:42 DEBUG : 3i9du405pfogq3ncai6pg7ouio: Rmdir: contains trashed file: "982d3pss7t5pn0il16r2foj31s" 2025/04/26 02:23:43 DEBUG : 2bsvlrk2ne1lfitm6tttcu0qt8: Rmdir: contains trashed file: "89l8renevh3mji1c8r1p7qn6tg" --- PASS: TestSyncIgnoreErrors (13.94s) === RUN TestSyncAfterChangingModtimeOnly run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-datebod4zayo'", Local "Local file system at /tmp/rclone381040261", Modify Window "1ms" 2025/04/26 02:23:46 DEBUG : empty space: md5 = 21e4b34a19fb230878520d125b659844 OK 2025/04/26 02:23:46 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-datebod4zayo': Waiting for checks to finish 2025/04/26 02:23:46 DEBUG : empty space: Modification times differ by -95456h54m52.624456789s: 2011-12-25 12:59:59.123456789 +0000 UTC, 2001-02-03 04:05:06.499 +0000 UTC 2025/04/26 02:23:46 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-datebod4zayo': Waiting for transfers to finish 2025/04/26 02:23:46 NOTICE: empty space: Skipped copy as --dry-run is set (size 1) 2025/04/26 02:23:46 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-datebod4zayo'", Local "Local file system at /tmp/rclone381040261", Modify Window "1ms" 2025/04/26 02:23:46 DEBUG : empty space: Modification times differ by -95456h54m52.624456789s: 2011-12-25 12:59:59.123456789 +0000 UTC, 2001-02-03 04:05:06.499 +0000 UTC 2025/04/26 02:23:46 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-datebod4zayo': Waiting for checks to finish 2025/04/26 02:23:46 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-datebod4zayo': Waiting for transfers to finish 2025/04/26 02:23:47 DEBUG : empty space: md5 = 06774ef79a30673279ae03601d2010f2 OK 2025/04/26 02:23:47 INFO : empty space: Copied (replaced existing) 2025/04/26 02:23:47 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-datebod4zayo'", Local "Local file system at /tmp/rclone381040261", Modify Window "1ms" --- PASS: TestSyncAfterChangingModtimeOnly (5.34s) === RUN TestSyncAfterChangingModtimeOnlyWithNoUpdateModTime run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-datebod4zayo'", Local "Local file system at /tmp/rclone381040261", Modify Window "1ms" sync_test.go:1016: Can't check this if no hashes supported --- PASS: TestSyncAfterChangingModtimeOnlyWithNoUpdateModTime (0.42s) === RUN TestSyncDoesntUpdateModtime run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-datebod4zayo'", Local "Local file system at /tmp/rclone381040261", Modify Window "1ms" 2025/04/26 02:23:51 DEBUG : foo: md5 = fa2e938bcad83dffe07bc9b76a144cc2 OK 2025/04/26 02:23:52 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-datebod4zayo': Waiting for checks to finish 2025/04/26 02:23:52 DEBUG : foo: Modification times differ by -95456h54m52.624456789s: 2011-12-25 12:59:59.123456789 +0000 UTC, 2001-02-03 04:05:06.499 +0000 UTC 2025/04/26 02:23:52 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-datebod4zayo': Waiting for transfers to finish 2025/04/26 02:23:53 DEBUG : foo: md5 = e715de5097c4236cd50c87f1f8cb9aca OK 2025/04/26 02:23:53 INFO : foo: Copied (replaced existing) 2025/04/26 02:23:53 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-datebod4zayo'", Local "Local file system at /tmp/rclone381040261", Modify Window "1ms" --- PASS: TestSyncDoesntUpdateModtime (4.21s) === RUN TestSyncAfterAddingAFile run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-datebod4zayo'", Local "Local file system at /tmp/rclone381040261", Modify Window "1ms" 2025/04/26 02:23:55 DEBUG : empty space: md5 = 48f0eb474ade748d05d39142b63439ca OK 2025/04/26 02:23:56 DEBUG : empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/04/26 02:23:56 DEBUG : potato: Need to transfer - File not found at Destination 2025/04/26 02:23:56 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-datebod4zayo': Waiting for checks to finish 2025/04/26 02:23:56 DEBUG : empty space: Unchanged skipping 2025/04/26 02:23:56 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-datebod4zayo': Waiting for transfers to finish 2025/04/26 02:23:57 DEBUG : potato: md5 = c03557ab254a4e1ed950ebd6be9afd6a OK 2025/04/26 02:23:57 INFO : potato: Copied (new) 2025/04/26 02:23:57 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-datebod4zayo'", Local "Local file system at /tmp/rclone381040261", Modify Window "1ms" --- PASS: TestSyncAfterAddingAFile (5.02s) === RUN TestSyncAfterChangingFilesSizeOnly run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-datebod4zayo'", Local "Local file system at /tmp/rclone381040261", Modify Window "1ms" 2025/04/26 02:24:01 DEBUG : potato: md5 = 70e7dbcec9a8f13a01de4c933cab7bc7 OK 2025/04/26 02:24:01 DEBUG : potato: Sizes differ (src 21 vs dst 60) 2025/04/26 02:24:01 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-datebod4zayo': Waiting for checks to finish 2025/04/26 02:24:01 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-datebod4zayo': Waiting for transfers to finish 2025/04/26 02:24:02 DEBUG : potato: md5 = fd9823322a8561be03f6c95c7ba4c9ed OK 2025/04/26 02:24:02 INFO : potato: Copied (replaced existing) 2025/04/26 02:24:02 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-datebod4zayo'", Local "Local file system at /tmp/rclone381040261", Modify Window "1ms" --- PASS: TestSyncAfterChangingFilesSizeOnly (4.29s) === RUN TestSyncAfterChangingContentsOnly run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-datebod4zayo'", Local "Local file system at /tmp/rclone381040261", Modify Window "1ms" 2025/04/26 02:24:05 DEBUG : potato: md5 = eb00d586bd05061827ff9411ee5af9dc OK 2025/04/26 02:24:05 DEBUG : potato: Modification times differ by 119h59m59.876543211s: 2011-12-25 12:59:59.123456789 +0000 UTC, 2011-12-30 12:59:59 +0000 UTC 2025/04/26 02:24:05 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-datebod4zayo': Waiting for checks to finish 2025/04/26 02:24:05 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-datebod4zayo': Waiting for transfers to finish 2025/04/26 02:24:06 DEBUG : potato: md5 = 8599c3490a8248bf2f301044bc399fed OK 2025/04/26 02:24:06 INFO : potato: Copied (replaced existing) 2025/04/26 02:24:06 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-datebod4zayo'", Local "Local file system at /tmp/rclone381040261", Modify Window "1ms" --- PASS: TestSyncAfterChangingContentsOnly (4.58s) === RUN TestSyncAfterRemovingAFileAndAddingAFileDryRun run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-datebod4zayo'", Local "Local file system at /tmp/rclone381040261", Modify Window "1ms" 2025/04/26 02:24:09 DEBUG : potato: md5 = 8899b0b50887d1f03a8669cf36256164 OK 2025/04/26 02:24:11 DEBUG : empty space: md5 = 1a6c5e1b6c308774828542b007505447 OK 2025/04/26 02:24:11 DEBUG : potato2: Need to transfer - File not found at Destination 2025/04/26 02:24:11 DEBUG : empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/04/26 02:24:11 NOTICE: potato2: Skipped copy as --dry-run is set (size 60) 2025/04/26 02:24:11 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-datebod4zayo': Waiting for checks to finish 2025/04/26 02:24:11 DEBUG : empty space: Unchanged skipping 2025/04/26 02:24:11 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-datebod4zayo': Waiting for transfers to finish 2025/04/26 02:24:11 DEBUG : Waiting for deletions to finish 2025/04/26 02:24:11 NOTICE: potato: Skipped delete as --dry-run is set (size 21) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-datebod4zayo'", Local "Local file system at /tmp/rclone381040261", Modify Window "1ms" --- PASS: TestSyncAfterRemovingAFileAndAddingAFileDryRun (4.93s) === RUN TestSyncAfterRemovingAFileAndAddingAFile run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-datebod4zayo'", Local "Local file system at /tmp/rclone381040261", Modify Window "1ms" 2025/04/26 02:24:14 DEBUG : potato: md5 = 38c0a600a461ce52c34b9bddb57aa29a OK 2025/04/26 02:24:16 DEBUG : empty space: md5 = ea84efb361f449c3dd761cea1d19a0d9 OK 2025/04/26 02:24:16 DEBUG : empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/04/26 02:24:16 DEBUG : potato2: Need to transfer - File not found at Destination 2025/04/26 02:24:16 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-datebod4zayo': Waiting for checks to finish 2025/04/26 02:24:16 DEBUG : empty space: Unchanged skipping 2025/04/26 02:24:16 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-datebod4zayo': Waiting for transfers to finish 2025/04/26 02:24:17 DEBUG : potato2: md5 = ed2e9d18227de60ade0139f3847c3398 OK 2025/04/26 02:24:17 INFO : potato2: Copied (new) 2025/04/26 02:24:17 DEBUG : Waiting for deletions to finish 2025/04/26 02:24:18 INFO : potato: Deleted run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-datebod4zayo'", Local "Local file system at /tmp/rclone381040261", Modify Window "1ms" --- PASS: TestSyncAfterRemovingAFileAndAddingAFile (7.00s) === RUN TestSyncAfterRemovingAFileAndAddingAFileSubDir run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-datebod4zayo'", Local "Local file system at /tmp/rclone381040261", Modify Window "1ms" 2025/04/26 02:24:22 DEBUG : b/potato: md5 = 237c816d33e423b41119e8ced2b138a9 OK 2025/04/26 02:24:24 DEBUG : c/non empty space: md5 = b0459ea8b70f1eca18a44498e93f38d4 OK 2025/04/26 02:24:24 INFO : d: Making directory 2025/04/26 02:24:25 INFO : d/e: Making directory 2025/04/26 02:24:27 DEBUG : Added delayed dir = "a", newDst= 2025/04/26 02:24:28 INFO : c: Set directory modification time (using SetModTime) 2025/04/26 02:24:28 DEBUG : Added delayed dir = "c", newDst=c 2025/04/26 02:24:28 DEBUG : c/non empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/04/26 02:24:28 DEBUG : a/potato2: Need to transfer - File not found at Destination 2025/04/26 02:24:28 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-datebod4zayo': Waiting for checks to finish 2025/04/26 02:24:28 DEBUG : c/non empty space: Unchanged skipping 2025/04/26 02:24:28 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-datebod4zayo': Waiting for transfers to finish 2025/04/26 02:24:30 DEBUG : a/potato2: md5 = 364be702f8df730033a46cb905844734 OK 2025/04/26 02:24:30 INFO : a/potato2: Copied (new) 2025/04/26 02:24:30 DEBUG : Waiting for deletions to finish 2025/04/26 02:24:30 INFO : b/potato: Deleted 2025/04/26 02:24:31 INFO : a: Set directory modification time (using DirSetModTime) 2025/04/26 02:24:31 INFO : d/e: Removing directory 2025/04/26 02:24:31 INFO : d: Removing directory 2025/04/26 02:24:31 DEBUG : ka6id8d20d3s5ktapedlphgta8: Rmdir: contains trashed file: "r8sppajuabeak3sbgj2ak8vuf8" 2025/04/26 02:24:32 INFO : b: Removing directory 2025/04/26 02:24:32 DEBUG : 32d8ua6196mc1r7qkfog53rkg0: Rmdir: contains trashed file: "2m507n64kafsi59v9q71r281a4" 2025/04/26 02:24:33 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-datebod4zayo': deleted 3 directories run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-datebod4zayo'", Local "Local file system at /tmp/rclone381040261", Modify Window "1ms" 2025/04/26 02:24:35 DEBUG : 3i9du405pfogq3ncai6pg7ouio: Rmdir: contains trashed file: "982d3pss7t5pn0il16r2foj31s" 2025/04/26 02:24:35 DEBUG : 2bsvlrk2ne1lfitm6tttcu0qt8: Rmdir: contains trashed file: "89l8renevh3mji1c8r1p7qn6tg" --- PASS: TestSyncAfterRemovingAFileAndAddingAFileSubDir (16.30s) === RUN TestSyncAfterRemovingAFileAndAddingAFileSubDirWithErrors run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-datebod4zayo'", Local "Local file system at /tmp/rclone381040261", Modify Window "1ms" 2025/04/26 02:24:38 DEBUG : b/potato: md5 = 87f4a696d666f32d5e99bd692fcdffa5 OK 2025/04/26 02:24:40 DEBUG : c/non empty space: md5 = 38b412686d32e95096661f5014b9ddf8 OK 2025/04/26 02:24:40 INFO : d: Making directory 2025/04/26 02:24:42 DEBUG : Added delayed dir = "a", newDst= 2025/04/26 02:24:42 INFO : c: Set directory modification time (using SetModTime) 2025/04/26 02:24:42 DEBUG : Added delayed dir = "c", newDst=c 2025/04/26 02:24:42 DEBUG : c/non empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/04/26 02:24:42 DEBUG : a/potato2: Need to transfer - File not found at Destination 2025/04/26 02:24:42 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-datebod4zayo': Waiting for checks to finish 2025/04/26 02:24:42 DEBUG : c/non empty space: Unchanged skipping 2025/04/26 02:24:42 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-datebod4zayo': Waiting for transfers to finish 2025/04/26 02:24:44 DEBUG : a/potato2: md5 = 3243fdfdafab53e430826991754c9bec OK 2025/04/26 02:24:44 INFO : a/potato2: Copied (new) 2025/04/26 02:24:44 ERROR : Encrypted drive 'TestCryptDrive:rclone-test-datebod4zayo': not deleting files as there were IO errors 2025/04/26 02:24:44 INFO : a: Set directory modification time (using DirSetModTime) 2025/04/26 02:24:44 ERROR : Encrypted drive 'TestCryptDrive:rclone-test-datebod4zayo': not deleting directories as there were IO errors run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-datebod4zayo'", Local "Local file system at /tmp/rclone381040261", Modify Window "1ms" 2025/04/26 02:24:47 DEBUG : 3i9du405pfogq3ncai6pg7ouio: Rmdir: contains trashed file: "982d3pss7t5pn0il16r2foj31s" 2025/04/26 02:24:48 DEBUG : 32d8ua6196mc1r7qkfog53rkg0: Rmdir: contains trashed file: "2m507n64kafsi59v9q71r281a4" 2025/04/26 02:24:49 DEBUG : 2bsvlrk2ne1lfitm6tttcu0qt8: Rmdir: contains trashed file: "89l8renevh3mji1c8r1p7qn6tg" --- PASS: TestSyncAfterRemovingAFileAndAddingAFileSubDirWithErrors (13.48s) === RUN TestSyncDeleteAfter --- PASS: TestSyncDeleteAfter (0.00s) === RUN TestSyncDeleteDuring run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-datebod4zayo'", Local "Local file system at /tmp/rclone381040261", Modify Window "1ms" 2025/04/26 02:24:51 DEBUG : potato: md5 = 17f155fe067ab6d5312b5551ce885d6c OK 2025/04/26 02:24:52 DEBUG : empty space: md5 = 18af182d9bd03e521585733ae59b4ebd OK 2025/04/26 02:24:53 DEBUG : Waiting for deletions to finish 2025/04/26 02:24:53 DEBUG : empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/04/26 02:24:53 DEBUG : potato2: Need to transfer - File not found at Destination 2025/04/26 02:24:53 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-datebod4zayo': Waiting for checks to finish 2025/04/26 02:24:53 DEBUG : empty space: Unchanged skipping 2025/04/26 02:24:53 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-datebod4zayo': Waiting for transfers to finish 2025/04/26 02:24:53 INFO : potato: Deleted 2025/04/26 02:24:54 DEBUG : potato2: md5 = c601525f3325db094b608863bfe92304 OK 2025/04/26 02:24:54 INFO : potato2: Copied (new) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-datebod4zayo'", Local "Local file system at /tmp/rclone381040261", Modify Window "1ms" --- PASS: TestSyncDeleteDuring (6.31s) === RUN TestSyncDeleteBefore run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-datebod4zayo'", Local "Local file system at /tmp/rclone381040261", Modify Window "1ms" 2025/04/26 02:24:57 DEBUG : potato: md5 = 0d3206b77875a73547693496df1f471f OK 2025/04/26 02:24:58 DEBUG : empty space: md5 = f028b92172cbf1e65faf53a12b0b6064 OK 2025/04/26 02:24:59 DEBUG : Waiting for deletions to finish 2025/04/26 02:24:59 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-datebod4zayo': Waiting for checks to finish 2025/04/26 02:24:59 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-datebod4zayo': Waiting for transfers to finish 2025/04/26 02:24:59 INFO : potato: Deleted 2025/04/26 02:25:00 DEBUG : empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/04/26 02:25:00 DEBUG : potato2: Need to transfer - File not found at Destination 2025/04/26 02:25:00 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-datebod4zayo': Waiting for checks to finish 2025/04/26 02:25:00 DEBUG : empty space: Unchanged skipping 2025/04/26 02:25:00 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-datebod4zayo': Waiting for transfers to finish 2025/04/26 02:25:01 DEBUG : potato2: md5 = 009a4e0e4cbdc09ab43f2e23ea96d1fc OK 2025/04/26 02:25:01 INFO : potato2: Copied (new) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-datebod4zayo'", Local "Local file system at /tmp/rclone381040261", Modify Window "1ms" --- PASS: TestSyncDeleteBefore (6.74s) === RUN TestCopyDeleteBefore run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-datebod4zayo'", Local "Local file system at /tmp/rclone381040261", Modify Window "1ms" 2025/04/26 02:25:04 DEBUG : potato: md5 = 58f1dfeb83e79372c0cd1e832277f8af OK 2025/04/26 02:25:04 DEBUG : potato2: Need to transfer - File not found at Destination 2025/04/26 02:25:04 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-datebod4zayo': Waiting for checks to finish 2025/04/26 02:25:04 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-datebod4zayo': Waiting for transfers to finish 2025/04/26 02:25:06 DEBUG : potato2: md5 = 8d897a7101ee9dc5c89d73b208846412 OK 2025/04/26 02:25:06 INFO : potato2: Copied (new) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-datebod4zayo'", Local "Local file system at /tmp/rclone381040261", Modify Window "1ms" --- PASS: TestCopyDeleteBefore (4.86s) === RUN TestSyncWithExclude run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-datebod4zayo'", Local "Local file system at /tmp/rclone381040261", Modify Window "1ms" 2025/04/26 02:25:09 DEBUG : potato2: md5 = a6179e1780d82d45ce771cca5a07532e OK 2025/04/26 02:25:10 DEBUG : empty space: md5 = 84a3f99708ae22a8fc46cdab4b9315ba OK 2025/04/26 02:25:11 DEBUG : enormous: Excluded (Size Filter) 2025/04/26 02:25:11 DEBUG : enormous: Excluded 2025/04/26 02:25:11 DEBUG : potato2: Excluded (Size Filter) 2025/04/26 02:25:11 DEBUG : potato2: Excluded 2025/04/26 02:25:11 DEBUG : potato2: Excluded (Size Filter) 2025/04/26 02:25:11 DEBUG : empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/04/26 02:25:11 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-datebod4zayo': Waiting for checks to finish 2025/04/26 02:25:11 DEBUG : empty space: Unchanged skipping 2025/04/26 02:25:11 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-datebod4zayo': Waiting for transfers to finish 2025/04/26 02:25:11 DEBUG : Waiting for deletions to finish 2025/04/26 02:25:11 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-datebod4zayo'", Local "Local file system at /tmp/rclone381040261", Modify Window "1ms" 2025/04/26 02:25:11 DEBUG : enormous: Excluded (Size Filter) 2025/04/26 02:25:11 DEBUG : enormous: Excluded 2025/04/26 02:25:11 DEBUG : potato2: Excluded (Size Filter) 2025/04/26 02:25:11 DEBUG : potato2: Excluded 2025/04/26 02:25:11 DEBUG : potato2: Excluded (Size Filter) 2025/04/26 02:25:11 DEBUG : Local file system at /tmp/rclone381040261: Waiting for checks to finish 2025/04/26 02:25:11 DEBUG : empty space: Size and modification time the same (differ by 456.789µs, within tolerance 1ms) 2025/04/26 02:25:11 DEBUG : empty space: Unchanged skipping 2025/04/26 02:25:11 DEBUG : Local file system at /tmp/rclone381040261: Waiting for transfers to finish 2025/04/26 02:25:11 DEBUG : Waiting for deletions to finish 2025/04/26 02:25:11 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-datebod4zayo'", Local "Local file system at /tmp/rclone381040261", Modify Window "1ms" --- PASS: TestSyncWithExclude (5.75s) === RUN TestSyncWithExcludeAndDeleteExcluded run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-datebod4zayo'", Local "Local file system at /tmp/rclone381040261", Modify Window "1ms" 2025/04/26 02:25:15 DEBUG : potato2: md5 = 2101b23cc34ca999dd691db5ba19cb73 OK 2025/04/26 02:25:16 DEBUG : empty space: md5 = ab599936511cf2c11575681e981d788f OK 2025/04/26 02:25:17 DEBUG : enormous: md5 = 807c6a4fc921e5fcc61922f375b42edd OK 2025/04/26 02:25:17 DEBUG : enormous: Excluded (Size Filter) 2025/04/26 02:25:17 DEBUG : enormous: Excluded 2025/04/26 02:25:17 DEBUG : potato2: Excluded (Size Filter) 2025/04/26 02:25:17 DEBUG : potato2: Excluded 2025/04/26 02:25:18 DEBUG : empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/04/26 02:25:18 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-datebod4zayo': Waiting for checks to finish 2025/04/26 02:25:18 DEBUG : empty space: Unchanged skipping 2025/04/26 02:25:18 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-datebod4zayo': Waiting for transfers to finish 2025/04/26 02:25:18 DEBUG : Waiting for deletions to finish 2025/04/26 02:25:18 INFO : potato2: Deleted 2025/04/26 02:25:18 INFO : enormous: Deleted 2025/04/26 02:25:18 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-datebod4zayo'", Local "Local file system at /tmp/rclone381040261", Modify Window "1ms" 2025/04/26 02:25:19 DEBUG : empty space: Size and modification time the same (differ by 456.789µs, within tolerance 1ms) 2025/04/26 02:25:19 DEBUG : Local file system at /tmp/rclone381040261: Waiting for checks to finish 2025/04/26 02:25:19 DEBUG : empty space: Unchanged skipping 2025/04/26 02:25:19 DEBUG : Local file system at /tmp/rclone381040261: Waiting for transfers to finish 2025/04/26 02:25:19 DEBUG : Waiting for deletions to finish 2025/04/26 02:25:19 INFO : potato2: Deleted 2025/04/26 02:25:19 INFO : enormous: Deleted 2025/04/26 02:25:19 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-datebod4zayo'", Local "Local file system at /tmp/rclone381040261", Modify Window "1ms" --- PASS: TestSyncWithExcludeAndDeleteExcluded (6.88s) === RUN TestSyncWithUpdateOlder run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-datebod4zayo'", Local "Local file system at /tmp/rclone381040261", Modify Window "1ms" 2025/04/26 02:25:22 DEBUG : one: md5 = 7d347eb2d747c6c171e60599c907fdb8 OK 2025/04/26 02:25:23 DEBUG : two: md5 = 7b49bf0ce4c21b5fcfed044ca5381d66 OK 2025/04/26 02:25:24 DEBUG : three: md5 = 0b48e9b4cfc39ebf77d62ad705b39590 OK 2025/04/26 02:25:26 DEBUG : four: md5 = df8e8b3706fb98d0b5afcfab42f35887 OK 2025/04/26 02:25:26 DEBUG : five: Need to transfer - File not found at Destination 2025/04/26 02:25:26 DEBUG : four: Sizes differ (src 4 vs dst 8) 2025/04/26 02:25:26 DEBUG : one: Destination is newer than source, skipping 2025/04/26 02:25:26 DEBUG : three: Sizes identical 2025/04/26 02:25:26 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-datebod4zayo': Waiting for checks to finish 2025/04/26 02:25:26 DEBUG : four: Destination mod time is within 1s of source but files differ, transferring 2025/04/26 02:25:26 DEBUG : three: Destination mod time is within 1s of source and files identical, skipping 2025/04/26 02:25:26 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-datebod4zayo': Waiting for transfers to finish 2025/04/26 02:25:27 DEBUG : four: md5 = dec4a03d0b6f46adf56b93ada8769981 OK 2025/04/26 02:25:27 INFO : four: Copied (replaced existing) 2025/04/26 02:25:27 DEBUG : two: md5 = 7e977f31ae2dd0a52cd7cc449d265837 OK 2025/04/26 02:25:27 INFO : two: Copied (replaced existing) 2025/04/26 02:25:27 DEBUG : five: md5 = 598b345fd2162f4e79809ef3610ae2a2 OK 2025/04/26 02:25:27 INFO : five: Copied (new) 2025/04/26 02:25:27 DEBUG : Waiting for deletions to finish sync_test.go:1449: Skip test with --checksum as no hashes supported --- PASS: TestSyncWithUpdateOlder (9.84s) === 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-datebod4zayo'", Local "Local file system at /tmp/rclone381040261", Modify Window "1ms" sync_test.go:1538: Can track renames: false 2025/04/26 02:25:30 ERROR : Encrypted drive 'TestCryptDrive:rclone-test-datebod4zayo': Ignoring --track-renames as the source and destination do not have a common hash 2025/04/26 02:25:30 DEBUG : potato: Need to transfer - File not found at Destination 2025/04/26 02:25:30 DEBUG : yam: Need to transfer - File not found at Destination 2025/04/26 02:25:30 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-datebod4zayo': Waiting for checks to finish 2025/04/26 02:25:30 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-datebod4zayo': Waiting for transfers to finish 2025/04/26 02:25:32 DEBUG : potato: md5 = 63ba2fbb703499e49162674fe4204196 OK 2025/04/26 02:25:32 INFO : potato: Copied (new) 2025/04/26 02:25:32 DEBUG : yam: md5 = 0031222dee919d414495d763f6c75d55 OK 2025/04/26 02:25:32 INFO : yam: Copied (new) 2025/04/26 02:25:32 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-datebod4zayo'", Local "Local file system at /tmp/rclone381040261", Modify Window "1ms" 2025/04/26 02:25:32 ERROR : Encrypted drive 'TestCryptDrive:rclone-test-datebod4zayo': Ignoring --track-renames as the source and destination do not have a common hash 2025/04/26 02:25:32 DEBUG : potato: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/26 02:25:32 DEBUG : yaml: Need to transfer - File not found at Destination 2025/04/26 02:25:32 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-datebod4zayo': Waiting for checks to finish 2025/04/26 02:25:32 DEBUG : potato: Unchanged skipping 2025/04/26 02:25:32 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-datebod4zayo': Waiting for transfers to finish 2025/04/26 02:25:33 DEBUG : yaml: md5 = 315c105210f9b026deed61d0baa9be1b OK 2025/04/26 02:25:33 INFO : yaml: Copied (new) 2025/04/26 02:25:33 DEBUG : Waiting for deletions to finish 2025/04/26 02:25:34 INFO : yam: Deleted run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-datebod4zayo'", Local "Local file system at /tmp/rclone381040261", Modify Window "1ms" --- PASS: TestSyncWithTrackRenames (6.00s) === RUN TestParseRenamesStrategyModtime --- PASS: TestParseRenamesStrategyModtime (0.00s) === RUN TestRenamesStrategyModtime --- PASS: TestRenamesStrategyModtime (0.00s) === RUN TestSyncWithTrackRenamesStrategyModtime run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-datebod4zayo'", Local "Local file system at /tmp/rclone381040261", Modify Window "1ms" sync_test.go:1610: Can track renames: true 2025/04/26 02:25:36 INFO : Encrypted drive 'TestCryptDrive:rclone-test-datebod4zayo': Making map for --track-renames 2025/04/26 02:25:36 INFO : Encrypted drive 'TestCryptDrive:rclone-test-datebod4zayo': Finished making map for --track-renames 2025/04/26 02:25:36 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-datebod4zayo': Waiting for checks to finish 2025/04/26 02:25:36 DEBUG : yam: Need to transfer - No matching file found at Destination 2025/04/26 02:25:36 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-datebod4zayo': Waiting for renames to finish 2025/04/26 02:25:36 DEBUG : potato: Need to transfer - No matching file found at Destination 2025/04/26 02:25:36 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-datebod4zayo': Waiting for transfers to finish 2025/04/26 02:25:38 DEBUG : potato: md5 = c3df9f1d175a29cc11aa3d26323de8ba OK 2025/04/26 02:25:38 INFO : potato: Copied (new) 2025/04/26 02:25:38 DEBUG : yam: md5 = 252f8c6087d508afb5ab7c4a963921f4 OK 2025/04/26 02:25:38 INFO : yam: Copied (new) 2025/04/26 02:25:38 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-datebod4zayo'", Local "Local file system at /tmp/rclone381040261", Modify Window "1ms" 2025/04/26 02:25:38 DEBUG : potato: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/26 02:25:38 INFO : Encrypted drive 'TestCryptDrive:rclone-test-datebod4zayo': Making map for --track-renames 2025/04/26 02:25:38 INFO : Encrypted drive 'TestCryptDrive:rclone-test-datebod4zayo': Finished making map for --track-renames 2025/04/26 02:25:38 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-datebod4zayo': Waiting for checks to finish 2025/04/26 02:25:38 DEBUG : potato: Unchanged skipping 2025/04/26 02:25:38 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-datebod4zayo': Waiting for renames to finish 2025/04/26 02:25:39 INFO : yam: Moved (server-side) to: yaml 2025/04/26 02:25:39 INFO : yaml: Renamed from "yam" 2025/04/26 02:25:39 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-datebod4zayo': Waiting for transfers to finish 2025/04/26 02:25:39 DEBUG : Waiting for deletions to finish 2025/04/26 02:25:39 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-datebod4zayo'", Local "Local file system at /tmp/rclone381040261", Modify Window "1ms" --- PASS: TestSyncWithTrackRenamesStrategyModtime (4.90s) === RUN TestSyncWithTrackRenamesStrategyLeaf run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-datebod4zayo'", Local "Local file system at /tmp/rclone381040261", Modify Window "1ms" sync_test.go:1649: Can track renames: true 2025/04/26 02:25:41 DEBUG : Added delayed dir = "sub", newDst= 2025/04/26 02:25:41 INFO : Encrypted drive 'TestCryptDrive:rclone-test-datebod4zayo': Making map for --track-renames 2025/04/26 02:25:41 INFO : Encrypted drive 'TestCryptDrive:rclone-test-datebod4zayo': Finished making map for --track-renames 2025/04/26 02:25:41 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-datebod4zayo': Waiting for checks to finish 2025/04/26 02:25:41 DEBUG : potato: Need to transfer - No matching file found at Destination 2025/04/26 02:25:41 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-datebod4zayo': Waiting for renames to finish 2025/04/26 02:25:41 DEBUG : sub/yam: Need to transfer - No matching file found at Destination 2025/04/26 02:25:41 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-datebod4zayo': Waiting for transfers to finish 2025/04/26 02:25:43 DEBUG : sub/yam: md5 = 4a87a58bf0b612ec51ffdb64ed9b1034 OK 2025/04/26 02:25:43 INFO : sub/yam: Copied (new) 2025/04/26 02:25:43 DEBUG : potato: md5 = 985012e80fe97ee1bce1d43760bf934c OK 2025/04/26 02:25:43 INFO : potato: Copied (new) 2025/04/26 02:25:43 DEBUG : Waiting for deletions to finish 2025/04/26 02:25:44 INFO : sub: Set directory modification time (using DirSetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-datebod4zayo'", Local "Local file system at /tmp/rclone381040261", Modify Window "1ms" 2025/04/26 02:25:45 DEBUG : potato: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/26 02:25:45 DEBUG : potato: Unchanged skipping 2025/04/26 02:25:45 INFO : sub: Set directory modification time (using SetModTime) 2025/04/26 02:25:45 DEBUG : Added delayed dir = "sub", newDst=sub 2025/04/26 02:25:45 INFO : Encrypted drive 'TestCryptDrive:rclone-test-datebod4zayo': Making map for --track-renames 2025/04/26 02:25:45 INFO : Encrypted drive 'TestCryptDrive:rclone-test-datebod4zayo': Finished making map for --track-renames 2025/04/26 02:25:45 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-datebod4zayo': Waiting for checks to finish 2025/04/26 02:25:45 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-datebod4zayo': Waiting for renames to finish 2025/04/26 02:25:46 INFO : sub/yam: Moved (server-side) to: yam 2025/04/26 02:25:46 INFO : yam: Renamed from "sub/yam" 2025/04/26 02:25:46 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-datebod4zayo': Waiting for transfers to finish 2025/04/26 02:25:46 DEBUG : Waiting for deletions to finish 2025/04/26 02:25:46 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-datebod4zayo'", Local "Local file system at /tmp/rclone381040261", Modify Window "1ms" --- PASS: TestSyncWithTrackRenamesStrategyLeaf (8.00s) === RUN TestServerSideMoveLocal run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-datebod4zayo'", Local "Local file system at /tmp/rclone381040261", Modify Window "1ms" 2025/04/26 02:25:49 DEBUG : Creating backend with remote "/tmp/rclone381040261/dir1" 2025/04/26 02:25:49 DEBUG : Creating backend with remote "/tmp/rclone381040261/dir2" 2025/04/26 02:25:49 DEBUG : Local file system at /tmp/rclone381040261/dir2: Using server-side directory move 2025/04/26 02:25:49 INFO : Local file system at /tmp/rclone381040261/dir2: Server side directory move failed - fallback to file moves: can't copy directory - destination already exists 2025/04/26 02:25:49 DEBUG : file1.txt: Need to transfer - File not found at Destination 2025/04/26 02:25:49 DEBUG : Local file system at /tmp/rclone381040261/dir2: Waiting for checks to finish 2025/04/26 02:25:49 INFO : file1.txt: Moved (server-side) 2025/04/26 02:25:49 DEBUG : Local file system at /tmp/rclone381040261/dir2: Waiting for transfers to finish --- PASS: TestServerSideMoveLocal (0.46s) === RUN TestMoveWithDeleteEmptySrcDirs run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-datebod4zayo'", Local "Local file system at /tmp/rclone381040261", Modify Window "1ms" 2025/04/26 02:25:50 DEBUG : Added delayed dir = "nested", newDst= 2025/04/26 02:25:50 DEBUG : Added delayed dir = "sub dir", newDst= 2025/04/26 02:25:50 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2025/04/26 02:25:50 DEBUG : Added delayed dir = "nested/sub dir", newDst= 2025/04/26 02:25:50 DEBUG : nested/sub dir/file: Need to transfer - File not found at Destination 2025/04/26 02:25:50 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-datebod4zayo': Waiting for checks to finish 2025/04/26 02:25:50 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-datebod4zayo': Waiting for transfers to finish 2025/04/26 02:25:52 DEBUG : sub dir/hello world: md5 = 568744df0bf7f61cb17edb23b5d59291 OK 2025/04/26 02:25:52 INFO : sub dir/hello world: Copied (new) 2025/04/26 02:25:52 INFO : sub dir/hello world: Deleted 2025/04/26 02:25:53 DEBUG : nested/sub dir/file: md5 = 0c6fdfb3d89f6cae5cfe58bbee91a072 OK 2025/04/26 02:25:53 INFO : nested/sub dir/file: Copied (new) 2025/04/26 02:25:53 INFO : nested/sub dir/file: Deleted 2025/04/26 02:25:54 INFO : nested/sub dir: Set directory modification time (using DirSetModTime) 2025/04/26 02:25:54 INFO : sub dir: Set directory modification time (using DirSetModTime) 2025/04/26 02:25:54 INFO : nested: Set directory modification time (using DirSetModTime) 2025/04/26 02:25:54 INFO : sub dir: Removing directory 2025/04/26 02:25:54 INFO : nested/sub dir: Removing directory 2025/04/26 02:25:54 INFO : nested: Removing directory 2025/04/26 02:25:54 DEBUG : Local file system at /tmp/rclone381040261: deleted 3 directories run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-datebod4zayo'", Local "Local file system at /tmp/rclone381040261", Modify Window "1ms" 2025/04/26 02:25:56 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" 2025/04/26 02:25:57 DEBUG : 37qp6d1gohacv723ij3brofbu8/14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "ftp4kuv8se7tqduu6pmmcvjsmk" 2025/04/26 02:25:58 DEBUG : 37qp6d1gohacv723ij3brofbu8: Rmdir: contains trashed file: "14begaa36ih249fgrnfk6nulg0" --- PASS: TestMoveWithDeleteEmptySrcDirs (9.20s) === RUN TestMoveWithoutDeleteEmptySrcDirs run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-datebod4zayo'", Local "Local file system at /tmp/rclone381040261", Modify Window "1ms" 2025/04/26 02:25:59 DEBUG : Added delayed dir = "nested", newDst= 2025/04/26 02:25:59 DEBUG : Added delayed dir = "sub dir", newDst= 2025/04/26 02:25:59 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2025/04/26 02:25:59 DEBUG : Added delayed dir = "nested/sub dir", newDst= 2025/04/26 02:25:59 DEBUG : nested/sub dir/file: Need to transfer - File not found at Destination 2025/04/26 02:25:59 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-datebod4zayo': Waiting for checks to finish 2025/04/26 02:25:59 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-datebod4zayo': Waiting for transfers to finish 2025/04/26 02:26:01 DEBUG : sub dir/hello world: md5 = 2201825601dc15ad28be4c85cc895851 OK 2025/04/26 02:26:01 INFO : sub dir/hello world: Copied (new) 2025/04/26 02:26:01 INFO : sub dir/hello world: Deleted 2025/04/26 02:26:03 DEBUG : nested/sub dir/file: md5 = 97595b563995d416ccd29d827b422fb8 OK 2025/04/26 02:26:03 INFO : nested/sub dir/file: Copied (new) 2025/04/26 02:26:03 INFO : nested/sub dir/file: Deleted 2025/04/26 02:26:03 INFO : nested/sub dir: Set directory modification time (using DirSetModTime) 2025/04/26 02:26:03 INFO : nested: Set directory modification time (using DirSetModTime) 2025/04/26 02:26:03 INFO : sub dir: Set directory modification time (using DirSetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-datebod4zayo'", Local "Local file system at /tmp/rclone381040261", Modify Window "1ms" 2025/04/26 02:26:06 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" 2025/04/26 02:26:07 DEBUG : 37qp6d1gohacv723ij3brofbu8/14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "ftp4kuv8se7tqduu6pmmcvjsmk" 2025/04/26 02:26:07 DEBUG : 37qp6d1gohacv723ij3brofbu8: Rmdir: contains trashed file: "14begaa36ih249fgrnfk6nulg0" --- PASS: TestMoveWithoutDeleteEmptySrcDirs (9.48s) === RUN TestMoveWithIgnoreExisting run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-datebod4zayo'", Local "Local file system at /tmp/rclone381040261", Modify Window "1ms" 2025/04/26 02:26:08 DEBUG : existing: Need to transfer - File not found at Destination 2025/04/26 02:26:08 DEBUG : existing-b: Need to transfer - File not found at Destination 2025/04/26 02:26:08 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-datebod4zayo': Waiting for checks to finish 2025/04/26 02:26:08 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-datebod4zayo': Waiting for transfers to finish 2025/04/26 02:26:10 DEBUG : existing-b: md5 = 00cdfe313231b31af66af8562fb41f2a OK 2025/04/26 02:26:10 INFO : existing-b: Copied (new) 2025/04/26 02:26:10 INFO : existing-b: Deleted 2025/04/26 02:26:11 DEBUG : existing: md5 = 361e643b4d9213252a4ce8dd5029b57c OK 2025/04/26 02:26:11 INFO : existing: Copied (new) 2025/04/26 02:26:11 INFO : existing: Deleted 2025/04/26 02:26:11 DEBUG : existing: Destination exists, skipping 2025/04/26 02:26:11 DEBUG : existing: Not removing source file as destination file exists and --ignore-existing is set 2025/04/26 02:26:11 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-datebod4zayo': Waiting for checks to finish 2025/04/26 02:26:11 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-datebod4zayo': Waiting for transfers to finish 2025/04/26 02:26:11 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-datebod4zayo'", Local "Local file system at /tmp/rclone381040261", Modify Window "1ms" --- PASS: TestMoveWithIgnoreExisting (4.78s) === RUN TestServerSideMove run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-datebod4zayo'", Local "Local file system at /tmp/rclone381040261", Modify Window "1ms" 2025/04/26 02:26:13 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-kucokes9jisa" 2025/04/26 02:26:13 DEBUG : Creating backend with remote "TestDrive:crypt/8jgffh0o6kgove0r4nsgdj3pisokqto5jvcjkvmoeg537n0a8980" 2025/04/26 02:26:15 DEBUG : potato2: md5 = 5f317d1fbe88e3198beb81adf6077e66 OK 2025/04/26 02:26:17 DEBUG : empty space: md5 = 5b5ce4a46fa5a77d777a3fde8f56eed0 OK 2025/04/26 02:26:18 DEBUG : potato3: md5 = fc3aa97f7ae201da391a840a9d02c805 OK sync_test.go:1705: Server side move (if possible) Encrypted drive 'TestCryptDrive:rclone-test-datebod4zayo' -> Encrypted drive 'TestCryptDrive:rclone-test-kucokes9jisa' 2025/04/26 02:26:20 DEBUG : empty space: md5 = c4e22387e03aa762e6eba2ebf4694250 OK 2025/04/26 02:26:21 DEBUG : potato3: md5 = 1fa0e251a2540080c38019c53bb2f309 OK 2025/04/26 02:26:22 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-kucokes9jisa': Using server-side directory move 2025/04/26 02:26:22 INFO : Encrypted drive 'TestCryptDrive:rclone-test-kucokes9jisa': Server side directory move failed - fallback to file moves: can't copy directory - destination already exists 2025/04/26 02:26:22 DEBUG : potato2: Need to transfer - File not found at Destination 2025/04/26 02:26:22 DEBUG : empty space: Size and modification time the same (differ by 0s, within tolerance 1ms) 2025/04/26 02:26:22 DEBUG : potato3: Sizes differ (src 68 vs dst 60) 2025/04/26 02:26:22 DEBUG : empty space: Unchanged skipping 2025/04/26 02:26:22 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-kucokes9jisa': Waiting for checks to finish 2025/04/26 02:26:22 INFO : potato3: Deleted 2025/04/26 02:26:22 INFO : empty space: Deleted 2025/04/26 02:26:22 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-kucokes9jisa': Waiting for transfers to finish 2025/04/26 02:26:22 INFO : potato2: Moved (server-side) 2025/04/26 02:26:23 INFO : potato3: Moved (server-side) 2025/04/26 02:26:23 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-hivemew8yade" 2025/04/26 02:26:23 DEBUG : Creating backend with remote "TestDrive:crypt/desk2lv40lo9lu89v79h263a95sla23efesko4dfi2l7it9vtjsg" 2025/04/26 02:26:24 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hivemew8yade': Using server-side directory move 2025/04/26 02:26:25 INFO : Encrypted drive 'TestCryptDrive:rclone-test-hivemew8yade': Server side directory move succeeded 2025/04/26 02:26:26 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hivemew8yade': Purge remote 2025/04/26 02:26:26 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-kucokes9jisa': Purge remote 2025/04/26 02:26:26 NOTICE: purge failed: directory not found --- PASS: TestServerSideMove (13.86s) === RUN TestServerSideMoveWithFilter run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-datebod4zayo'", Local "Local file system at /tmp/rclone381040261", Modify Window "1ms" 2025/04/26 02:26:27 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-kobesuj5felo" 2025/04/26 02:26:27 DEBUG : Creating backend with remote "TestDrive:crypt/6ti1rp8650ok7eaa19di7idjtfq120l3utajl68d0tqbce7rpfr0" 2025/04/26 02:26:29 DEBUG : potato2: md5 = d8c1df41a931e969a0b553de7058da10 OK 2025/04/26 02:26:30 DEBUG : empty space: md5 = 2cfd71fbc4b81592f1f9fbbb0b37806f OK 2025/04/26 02:26:31 DEBUG : potato3: md5 = 7d9b2d40aebf29538011d6f7d2089eca OK sync_test.go:1705: Server side move (if possible) Encrypted drive 'TestCryptDrive:rclone-test-datebod4zayo' -> Encrypted drive 'TestCryptDrive:rclone-test-kobesuj5felo' 2025/04/26 02:26:34 DEBUG : empty space: md5 = 30811a632c5979633d0045041761a978 OK 2025/04/26 02:26:35 DEBUG : potato3: md5 = 69a059f841686e4b8212f8e0df834d9b OK 2025/04/26 02:26:35 DEBUG : empty space: Excluded (Size Filter) 2025/04/26 02:26:35 DEBUG : empty space: Excluded (Size Filter) 2025/04/26 02:26:35 DEBUG : potato2: Need to transfer - File not found at Destination 2025/04/26 02:26:35 DEBUG : potato3: Sizes differ (src 68 vs dst 60) 2025/04/26 02:26:35 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-kobesuj5felo': Waiting for checks to finish 2025/04/26 02:26:35 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-kobesuj5felo': Waiting for transfers to finish 2025/04/26 02:26:36 INFO : potato3: Deleted 2025/04/26 02:26:36 INFO : potato2: Moved (server-side) 2025/04/26 02:26:36 INFO : potato3: Moved (server-side) 2025/04/26 02:26:37 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-dedonun4goka" 2025/04/26 02:26:37 DEBUG : Creating backend with remote "TestDrive:crypt/7632mvkcdkp5ma3t29l3b238s5prm0ir1it96gfgqgepdq52cfg0" 2025/04/26 02:26:38 DEBUG : empty space: Excluded (Size Filter) 2025/04/26 02:26:38 DEBUG : potato2: Need to transfer - File not found at Destination 2025/04/26 02:26:38 DEBUG : potato3: Need to transfer - File not found at Destination 2025/04/26 02:26:38 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dedonun4goka': Waiting for checks to finish 2025/04/26 02:26:38 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dedonun4goka': Waiting for transfers to finish 2025/04/26 02:26:39 INFO : potato3: Moved (server-side) 2025/04/26 02:26:40 INFO : potato2: Moved (server-side) 2025/04/26 02:26:40 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-dedonun4goka': Purge remote 2025/04/26 02:26:41 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-kobesuj5felo': Purge remote --- PASS: TestServerSideMoveWithFilter (15.00s) === RUN TestServerSideMoveDeleteEmptySourceDirs run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-datebod4zayo'", Local "Local file system at /tmp/rclone381040261", Modify Window "1ms" 2025/04/26 02:26:42 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-hofisiz7zoge" 2025/04/26 02:26:42 DEBUG : Creating backend with remote "TestDrive:crypt/bblo0lfg4m4fqhlh1f8be4934hhngnei9h7b478fke7gjdkvroi0" 2025/04/26 02:26:44 DEBUG : potato2: md5 = 061e03d557f96c92c2eb86895b314667 OK 2025/04/26 02:26:45 DEBUG : empty space: md5 = 1e6de25ea851b7f1be6f2897b74da183 OK 2025/04/26 02:26:47 DEBUG : potato3: md5 = e9de49c4bcbaa788a4524c767b7d1b0c OK 2025/04/26 02:26:47 INFO : tomatoDir: Making directory sync_test.go:1705: Server side move (if possible) Encrypted drive 'TestCryptDrive:rclone-test-datebod4zayo' -> Encrypted drive 'TestCryptDrive:rclone-test-hofisiz7zoge' 2025/04/26 02:26:50 DEBUG : empty space: md5 = 66e0022fab1e5b75bf24ff741b0dad7d OK 2025/04/26 02:26:51 DEBUG : potato3: md5 = 7db38dd5c72f631faa9c814cd053440b OK 2025/04/26 02:26:51 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hofisiz7zoge': Using server-side directory move 2025/04/26 02:26:51 INFO : Encrypted drive 'TestCryptDrive:rclone-test-hofisiz7zoge': Server side directory move failed - fallback to file moves: can't copy directory - destination already exists 2025/04/26 02:26:52 DEBUG : potato2: Need to transfer - File not found at Destination 2025/04/26 02:26:52 DEBUG : Added delayed dir = "tomatoDir", newDst= 2025/04/26 02:26:52 DEBUG : empty space: Size and modification time the same (differ by 0s, within tolerance 1ms) 2025/04/26 02:26:52 DEBUG : empty space: Unchanged skipping 2025/04/26 02:26:52 DEBUG : potato3: Sizes differ (src 68 vs dst 60) 2025/04/26 02:26:52 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hofisiz7zoge': Waiting for checks to finish 2025/04/26 02:26:52 INFO : potato3: Deleted 2025/04/26 02:26:52 INFO : empty space: Deleted 2025/04/26 02:26:52 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hofisiz7zoge': Waiting for transfers to finish 2025/04/26 02:26:52 INFO : potato2: Moved (server-side) 2025/04/26 02:26:52 INFO : potato3: Moved (server-side) 2025/04/26 02:26:52 INFO : tomatoDir: Removing directory 2025/04/26 02:26:53 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-datebod4zayo': deleted 1 directories 2025/04/26 02:26:54 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-xafeles1zuna" 2025/04/26 02:26:54 DEBUG : Creating backend with remote "TestDrive:crypt/87tp52rm3u298s7529f00v3ouhd269769n1f9ml90se14b0658n0" 2025/04/26 02:26:55 INFO : tomatoDir: Making directory 2025/04/26 02:26:56 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-xafeles1zuna': Using server-side directory move 2025/04/26 02:26:56 INFO : Encrypted drive 'TestCryptDrive:rclone-test-xafeles1zuna': Server side directory move succeeded 2025/04/26 02:26:58 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-xafeles1zuna': Purge remote 2025/04/26 02:26:58 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hofisiz7zoge': Purge remote 2025/04/26 02:26:58 NOTICE: purge failed: directory not found --- PASS: TestServerSideMoveDeleteEmptySourceDirs (16.76s) === RUN TestServerSideMoveOverlap run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-datebod4zayo'", Local "Local file system at /tmp/rclone381040261", Modify Window "1ms" sync_test.go:1910: Skipping test as remote supports DirMove --- SKIP: TestServerSideMoveOverlap (0.44s) === RUN TestSyncOverlap run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-datebod4zayo'", Local "Local file system at /tmp/rclone381040261", Modify Window "1ms" 2025/04/26 02:26:59 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-datebod4zayo/rclone-sync-test" 2025/04/26 02:26:59 DEBUG : Creating backend with remote "TestDrive:crypt/qbp2hfftvuk4chug66bfh86l0s445cogcmp7icnphgefaamfkchg/i7355aa0sb89uagn75vfjqr6s3e3e1h2et8in57abn1fe8qfego0" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-datebod4zayo'", Local "Local file system at /tmp/rclone381040261", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-datebod4zayo'", Local "Local file system at /tmp/rclone381040261", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-datebod4zayo'", Local "Local file system at /tmp/rclone381040261", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-datebod4zayo'", Local "Local file system at /tmp/rclone381040261", Modify Window "1ms" --- PASS: TestSyncOverlap (3.58s) === RUN TestSyncOverlapWithFilter run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-datebod4zayo'", Local "Local file system at /tmp/rclone381040261", Modify Window "1ms" 2025/04/26 02:27:03 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-datebod4zayo/rclone-sync-test" 2025/04/26 02:27:03 DEBUG : Creating backend with remote "TestDrive:crypt/qbp2hfftvuk4chug66bfh86l0s445cogcmp7icnphgefaamfkchg/i7355aa0sb89uagn75vfjqr6s3e3e1h2et8in57abn1fe8qfego0" 2025/04/26 02:27:05 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-datebod4zayo/rclone-sync-test-include/layer2" 2025/04/26 02:27:05 DEBUG : Creating backend with remote "TestDrive:crypt/qbp2hfftvuk4chug66bfh86l0s445cogcmp7icnphgefaamfkchg/khf2vlblvnbf9ftevqm0htmss73hj1j5a7q328e4ohrgs7e2loe0/n01jpl9202nn9ec1rb75h0f1c4" 2025/04/26 02:27:08 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-datebod4zayo/rclone-sync-test-ignore-file" 2025/04/26 02:27:08 DEBUG : Creating backend with remote "TestDrive:crypt/qbp2hfftvuk4chug66bfh86l0s445cogcmp7icnphgefaamfkchg/kmf11jujl9uha3tjganvgpkn45bu778hb5vb5riug1c26b38k7sg" 2025/04/26 02:27:11 DEBUG : rclone-sync-test-ignore-file/.ignore: md5 = fb30d83f1eadc03cb9ec952037cd7c71 OK 2025/04/26 02:27:13 DEBUG : Added delayed dir = "rclone-sync-test-include", newDst= 2025/04/26 02:27:13 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-datebod4zayo/rclone-sync-test': Waiting for checks to finish 2025/04/26 02:27:13 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-datebod4zayo/rclone-sync-test': Waiting for transfers to finish 2025/04/26 02:27:13 DEBUG : Waiting for deletions to finish 2025/04/26 02:27:13 INFO : There was nothing to transfer 2025/04/26 02:27:15 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-datebod4zayo': Waiting for checks to finish 2025/04/26 02:27:15 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-datebod4zayo': Waiting for transfers to finish 2025/04/26 02:27:15 DEBUG : Waiting for deletions to finish 2025/04/26 02:27:15 INFO : rclone-sync-test-include: Removing directory 2025/04/26 02:27:15 DEBUG : khf2vlblvnbf9ftevqm0htmss73hj1j5a7q328e4ohrgs7e2loe0: Rmdir: contains file: "n01jpl9202nn9ec1rb75h0f1c4" 2025/04/26 02:27:15 DEBUG : rclone-sync-test-include: Failed to Rmdir: directory not empty 2025/04/26 02:27:15 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-datebod4zayo': failed to delete 1 directories 2025/04/26 02:27:15 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-datebod4zayo'", Local "Local file system at /tmp/rclone381040261", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-datebod4zayo'", Local "Local file system at /tmp/rclone381040261", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-datebod4zayo'", Local "Local file system at /tmp/rclone381040261", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-datebod4zayo'", Local "Local file system at /tmp/rclone381040261", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-datebod4zayo'", Local "Local file system at /tmp/rclone381040261", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-datebod4zayo'", Local "Local file system at /tmp/rclone381040261", Modify Window "1ms" 2025/04/26 02:27:17 DEBUG : Added delayed dir = "rclone-sync-test-include", newDst= 2025/04/26 02:27:17 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-datebod4zayo/rclone-sync-test-include/layer2': Waiting for checks to finish 2025/04/26 02:27:17 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-datebod4zayo/rclone-sync-test-include/layer2': Waiting for transfers to finish 2025/04/26 02:27:17 DEBUG : Waiting for deletions to finish 2025/04/26 02:27:17 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-datebod4zayo'", Local "Local file system at /tmp/rclone381040261", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-datebod4zayo'", Local "Local file system at /tmp/rclone381040261", Modify Window "1ms" 2025/04/26 02:27:19 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-datebod4zayo': Waiting for checks to finish 2025/04/26 02:27:19 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-datebod4zayo': Waiting for transfers to finish 2025/04/26 02:27:19 DEBUG : Waiting for deletions to finish 2025/04/26 02:27:19 INFO : rclone-sync-test-include: Removing directory 2025/04/26 02:27:19 DEBUG : khf2vlblvnbf9ftevqm0htmss73hj1j5a7q328e4ohrgs7e2loe0: Rmdir: contains file: "n01jpl9202nn9ec1rb75h0f1c4" 2025/04/26 02:27:19 DEBUG : rclone-sync-test-include: Failed to Rmdir: directory not empty 2025/04/26 02:27:19 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-datebod4zayo': failed to delete 1 directories 2025/04/26 02:27:19 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-datebod4zayo'", Local "Local file system at /tmp/rclone381040261", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-datebod4zayo'", Local "Local file system at /tmp/rclone381040261", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-datebod4zayo'", Local "Local file system at /tmp/rclone381040261", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-datebod4zayo'", Local "Local file system at /tmp/rclone381040261", Modify Window "1ms" 2025/04/26 02:27:21 DEBUG : Added delayed dir = "rclone-sync-test-include", newDst= 2025/04/26 02:27:21 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-datebod4zayo/rclone-sync-test-ignore-file': Waiting for checks to finish 2025/04/26 02:27:21 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-datebod4zayo/rclone-sync-test-ignore-file': Waiting for transfers to finish 2025/04/26 02:27:21 DEBUG : Waiting for deletions to finish 2025/04/26 02:27:21 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-datebod4zayo'", Local "Local file system at /tmp/rclone381040261", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-datebod4zayo'", Local "Local file system at /tmp/rclone381040261", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-datebod4zayo'", Local "Local file system at /tmp/rclone381040261", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-datebod4zayo'", Local "Local file system at /tmp/rclone381040261", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-datebod4zayo'", Local "Local file system at /tmp/rclone381040261", Modify Window "1ms" 2025/04/26 02:27:23 DEBUG : khf2vlblvnbf9ftevqm0htmss73hj1j5a7q328e4ohrgs7e2loe0: Rmdir: contains trashed file: "n01jpl9202nn9ec1rb75h0f1c4" 2025/04/26 02:27:23 DEBUG : kmf11jujl9uha3tjganvgpkn45bu778hb5vb5riug1c26b38k7sg: Rmdir: contains trashed file: "i0t74httmdlljg425j6tg570d8" --- PASS: TestSyncOverlapWithFilter (29.22s) === RUN TestSyncCompareDest run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-datebod4zayo'", Local "Local file system at /tmp/rclone381040261", Modify Window "1ms" 2025/04/26 02:27:32 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-datebod4zayo/dst" 2025/04/26 02:27:32 DEBUG : Creating backend with remote "TestDrive:crypt/qbp2hfftvuk4chug66bfh86l0s445cogcmp7icnphgefaamfkchg/31u3jie661vd5p8j7rtc3hgbh0" 2025/04/26 02:27:33 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-datebod4zayo/CompareDest" 2025/04/26 02:27:33 DEBUG : Creating backend with remote "TestDrive:crypt/qbp2hfftvuk4chug66bfh86l0s445cogcmp7icnphgefaamfkchg/gveqi14airsml4bgu7krj116o8" 2025/04/26 02:27:35 DEBUG : one: Need to transfer - File not found at Destination 2025/04/26 02:27:35 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-datebod4zayo/dst': Waiting for checks to finish 2025/04/26 02:27:35 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-datebod4zayo/dst': Waiting for transfers to finish 2025/04/26 02:27:37 DEBUG : one: md5 = 512c0718ee50ca9d61f11544292b4845 OK 2025/04/26 02:27:37 INFO : one: Copied (new) 2025/04/26 02:27:37 DEBUG : Waiting for deletions to finish 2025/04/26 02:27:38 DEBUG : one: Sizes differ (src 5 vs dst 3) 2025/04/26 02:27:38 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-datebod4zayo/dst': Waiting for checks to finish 2025/04/26 02:27:38 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-datebod4zayo/dst': Waiting for transfers to finish 2025/04/26 02:27:40 DEBUG : one: md5 = 1abbc04e9046fd0d5137b088cc283ffa OK 2025/04/26 02:27:40 INFO : one: Copied (replaced existing) 2025/04/26 02:27:40 DEBUG : Waiting for deletions to finish 2025/04/26 02:27:42 DEBUG : dst/one: md5 = f8c1facc2ed7c02b6eea4e08d4c30237 OK 2025/04/26 02:27:44 DEBUG : CompareDest/one: md5 = a729aa68c85c8552bad5139f6cd2b5e3 OK 2025/04/26 02:27:44 DEBUG : one: Sizes differ (src 5 vs dst 3) 2025/04/26 02:27:44 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-datebod4zayo/dst': Waiting for checks to finish 2025/04/26 02:27:45 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/04/26 02:27:45 DEBUG : one: Destination found in --compare-dest, skipping 2025/04/26 02:27:45 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-datebod4zayo/dst': Waiting for transfers to finish 2025/04/26 02:27:45 DEBUG : Waiting for deletions to finish 2025/04/26 02:27:45 INFO : There was nothing to transfer 2025/04/26 02:27:47 DEBUG : CompareDest/two: md5 = cc1bb3b54dd90cf741eef0b20de165c8 OK 2025/04/26 02:27:47 DEBUG : one: Sizes differ (src 5 vs dst 3) 2025/04/26 02:27:48 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/04/26 02:27:48 DEBUG : one: Destination found in --compare-dest, skipping 2025/04/26 02:27:48 DEBUG : two: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/04/26 02:27:48 DEBUG : two: Destination found in --compare-dest, skipping 2025/04/26 02:27:48 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-datebod4zayo/dst': Waiting for checks to finish 2025/04/26 02:27:48 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-datebod4zayo/dst': Waiting for transfers to finish 2025/04/26 02:27:48 DEBUG : Waiting for deletions to finish 2025/04/26 02:27:48 INFO : There was nothing to transfer 2025/04/26 02:27:48 DEBUG : one: Sizes differ (src 5 vs dst 3) 2025/04/26 02:27:48 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/04/26 02:27:48 DEBUG : one: Destination found in --compare-dest, skipping 2025/04/26 02:27:48 DEBUG : two: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/04/26 02:27:48 DEBUG : two: Destination found in --compare-dest, skipping 2025/04/26 02:27:48 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-datebod4zayo/dst': Waiting for checks to finish 2025/04/26 02:27:48 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-datebod4zayo/dst': Waiting for transfers to finish 2025/04/26 02:27:48 DEBUG : Waiting for deletions to finish 2025/04/26 02:27:48 INFO : There was nothing to transfer sync_test.go:2175: No hash on uploaded file so skipping compare timestamp test 2025/04/26 02:27:50 DEBUG : one: Sizes differ (src 5 vs dst 3) 2025/04/26 02:27:50 DEBUG : two: Sizes differ (src 5 vs dst 3) 2025/04/26 02:27:50 DEBUG : two: Need to transfer - File not found at Destination 2025/04/26 02:27:50 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-datebod4zayo/dst': Waiting for checks to finish 2025/04/26 02:27:50 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/04/26 02:27:50 DEBUG : one: Destination found in --compare-dest, skipping 2025/04/26 02:27:50 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-datebod4zayo/dst': Waiting for transfers to finish 2025/04/26 02:27:51 DEBUG : two: md5 = 277ad7b20eb126bedc67e30a023bbb8b OK 2025/04/26 02:27:51 INFO : two: Copied (new) 2025/04/26 02:27:51 DEBUG : Waiting for deletions to finish 2025/04/26 02:27:54 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k" 2025/04/26 02:27:54 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" 2025/04/26 02:27:54 DEBUG : gveqi14airsml4bgu7krj116o8: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k" 2025/04/26 02:27:54 DEBUG : gveqi14airsml4bgu7krj116o8: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" --- PASS: TestSyncCompareDest (23.25s) === RUN TestSyncMultipleCompareDest run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-datebod4zayo'", Local "Local file system at /tmp/rclone381040261", Modify Window "1ms" 2025/04/26 02:27:57 DEBUG : pre-dest1/1: md5 = 2d849e51af8b31273f3530f472a699a6 OK 2025/04/26 02:27:59 DEBUG : pre-dest2/2: md5 = 25d248acedb952cd09bf057c542d3fab OK 2025/04/26 02:27:59 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-datebod4zayo/dest" 2025/04/26 02:27:59 DEBUG : Creating backend with remote "TestDrive:crypt/qbp2hfftvuk4chug66bfh86l0s445cogcmp7icnphgefaamfkchg/rg03c1jvnehrrc617i0lnqjddc" 2025/04/26 02:28:01 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-datebod4zayo/pre-dest1" 2025/04/26 02:28:01 DEBUG : Creating backend with remote "TestDrive:crypt/qbp2hfftvuk4chug66bfh86l0s445cogcmp7icnphgefaamfkchg/bbnblvh6k061ssopqrp18kd7gc" 2025/04/26 02:28:02 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-datebod4zayo/pre-dest2" 2025/04/26 02:28:02 DEBUG : Creating backend with remote "TestDrive:crypt/qbp2hfftvuk4chug66bfh86l0s445cogcmp7icnphgefaamfkchg/dgicm1h6b5ejvlltm8eeif0bnk" 2025/04/26 02:28:03 DEBUG : 1: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/26 02:28:03 DEBUG : 1: Destination found in --compare-dest, skipping 2025/04/26 02:28:03 DEBUG : 2: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/26 02:28:03 DEBUG : 2: Destination found in --compare-dest, skipping 2025/04/26 02:28:04 DEBUG : 3: Need to transfer - File not found at Destination 2025/04/26 02:28:04 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-datebod4zayo/dest': Waiting for checks to finish 2025/04/26 02:28:04 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-datebod4zayo/dest': Waiting for transfers to finish 2025/04/26 02:28:06 DEBUG : 3: md5 = 3321bd90b41dbbed472e8c3f44f7c675 OK 2025/04/26 02:28:06 INFO : 3: Copied (new) 2025/04/26 02:28:06 DEBUG : Waiting for deletions to finish 2025/04/26 02:28:08 DEBUG : dgicm1h6b5ejvlltm8eeif0bnk: Rmdir: contains trashed file: "1ghu8geql9vrl726n32nrf65bc" 2025/04/26 02:28:09 DEBUG : bbnblvh6k061ssopqrp18kd7gc: Rmdir: contains trashed file: "skbfko3oil7es0lj68ob574sro" 2025/04/26 02:28:09 DEBUG : rg03c1jvnehrrc617i0lnqjddc: Rmdir: contains trashed file: "g072p7hmjchlnj0gibe64c1epg" --- PASS: TestSyncMultipleCompareDest (14.99s) === RUN TestSyncCopyDest run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-datebod4zayo'", Local "Local file system at /tmp/rclone381040261", Modify Window "1ms" 2025/04/26 02:28:10 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-datebod4zayo/dst" 2025/04/26 02:28:10 DEBUG : Creating backend with remote "TestDrive:crypt/qbp2hfftvuk4chug66bfh86l0s445cogcmp7icnphgefaamfkchg/31u3jie661vd5p8j7rtc3hgbh0" 2025/04/26 02:28:11 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-datebod4zayo/CopyDest" 2025/04/26 02:28:12 DEBUG : Creating backend with remote "TestDrive:crypt/qbp2hfftvuk4chug66bfh86l0s445cogcmp7icnphgefaamfkchg/d09o6po3f7bm6ce32vdgs8h9ls" 2025/04/26 02:28:13 DEBUG : one: Need to transfer - File not found at Destination 2025/04/26 02:28:13 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-datebod4zayo/dst': Waiting for checks to finish 2025/04/26 02:28:13 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-datebod4zayo/dst': Waiting for transfers to finish 2025/04/26 02:28:15 DEBUG : one: md5 = 1942b8c67349a9b4c7579fc7262df52d OK 2025/04/26 02:28:15 INFO : one: Copied (new) 2025/04/26 02:28:15 DEBUG : Waiting for deletions to finish 2025/04/26 02:28:17 DEBUG : one: Sizes differ (src 5 vs dst 3) 2025/04/26 02:28:17 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-datebod4zayo/dst': Waiting for checks to finish 2025/04/26 02:28:17 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-datebod4zayo/dst': Waiting for transfers to finish 2025/04/26 02:28:18 DEBUG : one: md5 = c77aae9d41a554194e8484f68ea9d2d1 OK 2025/04/26 02:28:18 INFO : one: Copied (replaced existing) 2025/04/26 02:28:18 DEBUG : Waiting for deletions to finish 2025/04/26 02:28:20 DEBUG : dst/one: md5 = b975bb3480eb8f138d9448c81672fe39 OK 2025/04/26 02:28:22 DEBUG : CopyDest/one: md5 = c023e43f4a9408d32b13534fcb4e423d OK 2025/04/26 02:28:22 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-datebod4zayo/BackupDir" 2025/04/26 02:28:22 DEBUG : Creating backend with remote "TestDrive:crypt/qbp2hfftvuk4chug66bfh86l0s445cogcmp7icnphgefaamfkchg/s6dbk3lfi7c9kfvo6j7bla9m0g" 2025/04/26 02:28:24 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-datebod4zayo/dst': Waiting for checks to finish 2025/04/26 02:28:24 DEBUG : one: Sizes differ (src 5 vs dst 3) 2025/04/26 02:28:24 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/04/26 02:28:24 DEBUG : one: Sizes differ (src 5 vs dst 3) 2025/04/26 02:28:26 INFO : one: Moved (server-side) 2025/04/26 02:28:27 INFO : one: Copied (server-side copy) 2025/04/26 02:28:27 DEBUG : one: Destination found in --copy-dest, using server-side copy 2025/04/26 02:28:27 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-datebod4zayo/dst': Waiting for transfers to finish 2025/04/26 02:28:27 DEBUG : Waiting for deletions to finish 2025/04/26 02:28:28 DEBUG : CopyDest/two: md5 = 1f4d7d16ef7992e3bc493ce3e60782ee OK 2025/04/26 02:28:29 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/04/26 02:28:29 DEBUG : one: Unchanged skipping 2025/04/26 02:28:29 DEBUG : two: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/04/26 02:28:30 INFO : two: Copied (server-side copy) 2025/04/26 02:28:30 DEBUG : two: Destination found in --copy-dest, using server-side copy 2025/04/26 02:28:30 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-datebod4zayo/dst': Waiting for checks to finish 2025/04/26 02:28:30 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-datebod4zayo/dst': Waiting for transfers to finish 2025/04/26 02:28:30 DEBUG : Waiting for deletions to finish 2025/04/26 02:28:31 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/04/26 02:28:31 DEBUG : one: Unchanged skipping 2025/04/26 02:28:31 DEBUG : two: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/04/26 02:28:31 DEBUG : two: Unchanged skipping 2025/04/26 02:28:31 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-datebod4zayo/dst': Waiting for checks to finish 2025/04/26 02:28:31 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-datebod4zayo/dst': Waiting for transfers to finish 2025/04/26 02:28:31 DEBUG : Waiting for deletions to finish 2025/04/26 02:28:31 INFO : There was nothing to transfer 2025/04/26 02:28:32 DEBUG : CopyDest/three: md5 = 28b355df5d6befb6c71da8d08dbf62d9 OK 2025/04/26 02:28:33 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/04/26 02:28:33 DEBUG : one: Unchanged skipping 2025/04/26 02:28:33 DEBUG : three: Sizes differ (src 7 vs dst 5) 2025/04/26 02:28:33 DEBUG : three: Destination not found in --copy-dest 2025/04/26 02:28:33 DEBUG : three: Need to transfer - File not found at Destination 2025/04/26 02:28:33 DEBUG : two: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/04/26 02:28:33 DEBUG : two: Unchanged skipping 2025/04/26 02:28:33 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-datebod4zayo/dst': Waiting for checks to finish 2025/04/26 02:28:33 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-datebod4zayo/dst': Waiting for transfers to finish 2025/04/26 02:28:35 DEBUG : three: md5 = e11385f938764762701ca80d4ad0df23 OK 2025/04/26 02:28:35 INFO : three: Copied (new) 2025/04/26 02:28:35 DEBUG : Waiting for deletions to finish 2025/04/26 02:28:39 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "b6jdmn2b1adrhc8vikh7edr9os" 2025/04/26 02:28:39 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" 2025/04/26 02:28:39 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k" 2025/04/26 02:28:40 DEBUG : d09o6po3f7bm6ce32vdgs8h9ls: Rmdir: contains trashed file: "b6jdmn2b1adrhc8vikh7edr9os" 2025/04/26 02:28:40 DEBUG : d09o6po3f7bm6ce32vdgs8h9ls: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k" 2025/04/26 02:28:40 DEBUG : d09o6po3f7bm6ce32vdgs8h9ls: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" 2025/04/26 02:28:40 DEBUG : s6dbk3lfi7c9kfvo6j7bla9m0g: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" --- PASS: TestSyncCopyDest (30.76s) === RUN TestSyncBackupDir run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-datebod4zayo'", Local "Local file system at /tmp/rclone381040261", Modify Window "1ms" 2025/04/26 02:28:43 DEBUG : dst/one: md5 = ddf08e184dac13ccb1aed5ff27825604 OK 2025/04/26 02:28:44 DEBUG : dst/two: md5 = d7ebc0941c0db6ea86e2b5d7855620cd OK 2025/04/26 02:28:45 DEBUG : dst/three.txt: md5 = 8f0dd6d9779620a94c275216f5cf8356 OK 2025/04/26 02:28:46 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-datebod4zayo/dst" 2025/04/26 02:28:46 DEBUG : Creating backend with remote "TestDrive:crypt/qbp2hfftvuk4chug66bfh86l0s445cogcmp7icnphgefaamfkchg/31u3jie661vd5p8j7rtc3hgbh0" 2025/04/26 02:28:46 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-datebod4zayo/backup" 2025/04/26 02:28:46 DEBUG : Creating backend with remote "TestDrive:crypt/qbp2hfftvuk4chug66bfh86l0s445cogcmp7icnphgefaamfkchg/1nrff024r7pq65ecp72fc28jb0" 2025/04/26 02:28:48 DEBUG : one: Sizes differ (src 4 vs dst 3) 2025/04/26 02:28:48 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/26 02:28:48 DEBUG : two: Unchanged skipping 2025/04/26 02:28:48 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-datebod4zayo/dst': Waiting for checks to finish 2025/04/26 02:28:50 INFO : one: Moved (server-side) 2025/04/26 02:28:50 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-datebod4zayo/dst': Waiting for transfers to finish 2025/04/26 02:28:51 DEBUG : one: md5 = ff42bb4fe6476e3f2920cafa99bacf57 OK 2025/04/26 02:28:51 INFO : one: Copied (new) 2025/04/26 02:28:51 DEBUG : Waiting for deletions to finish 2025/04/26 02:28:52 INFO : three.txt: Moved (server-side) 2025/04/26 02:28:52 INFO : three.txt: Moved into backup dir 2025/04/26 02:28:53 DEBUG : dst/three.txt: md5 = 6c6d0d7a7213c1b928d56fef41bfa0a4 OK 2025/04/26 02:28:54 DEBUG : one: Sizes differ (src 5 vs dst 4) 2025/04/26 02:28:54 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/26 02:28:54 DEBUG : two: Unchanged skipping 2025/04/26 02:28:54 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-datebod4zayo/dst': Waiting for checks to finish 2025/04/26 02:28:54 INFO : one: Deleted 2025/04/26 02:28:55 INFO : one: Moved (server-side) 2025/04/26 02:28:55 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-datebod4zayo/dst': Waiting for transfers to finish 2025/04/26 02:28:56 DEBUG : one: md5 = 60d46e5b7b4a25e31ee3b07f218b0e0c OK 2025/04/26 02:28:56 INFO : one: Copied (new) 2025/04/26 02:28:56 DEBUG : Waiting for deletions to finish 2025/04/26 02:28:57 INFO : three.txt: Deleted 2025/04/26 02:28:57 INFO : three.txt: Moved (server-side) 2025/04/26 02:28:57 INFO : three.txt: Moved into backup dir 2025/04/26 02:29:00 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" 2025/04/26 02:29:00 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k" 2025/04/26 02:29:01 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "tr2hj63d80ftlmvm6a952snjcc" 2025/04/26 02:29:01 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" 2025/04/26 02:29:01 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" 2025/04/26 02:29:01 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "tr2hj63d80ftlmvm6a952snjcc" --- PASS: TestSyncBackupDir (20.62s) === RUN TestSyncBackupDirWithSuffix run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-datebod4zayo'", Local "Local file system at /tmp/rclone381040261", Modify Window "1ms" 2025/04/26 02:29:03 DEBUG : dst/one: md5 = 9623c1e33fc35f77a0a777a372269bfc OK 2025/04/26 02:29:05 DEBUG : dst/two: md5 = bba026997d4d371f19cbf005c5974def OK 2025/04/26 02:29:06 DEBUG : dst/three.txt: md5 = 087e26287666f7950b8905810e0d9206 OK 2025/04/26 02:29:06 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-datebod4zayo/dst" 2025/04/26 02:29:06 DEBUG : Creating backend with remote "TestDrive:crypt/qbp2hfftvuk4chug66bfh86l0s445cogcmp7icnphgefaamfkchg/31u3jie661vd5p8j7rtc3hgbh0" 2025/04/26 02:29:07 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-datebod4zayo/backup" 2025/04/26 02:29:07 DEBUG : Creating backend with remote "TestDrive:crypt/qbp2hfftvuk4chug66bfh86l0s445cogcmp7icnphgefaamfkchg/1nrff024r7pq65ecp72fc28jb0" 2025/04/26 02:29:09 DEBUG : one: Sizes differ (src 4 vs dst 3) 2025/04/26 02:29:09 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/26 02:29:09 DEBUG : two: Unchanged skipping 2025/04/26 02:29:09 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-datebod4zayo/dst': Waiting for checks to finish 2025/04/26 02:29:10 INFO : one: Moved (server-side) to: one.bak 2025/04/26 02:29:10 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-datebod4zayo/dst': Waiting for transfers to finish 2025/04/26 02:29:11 DEBUG : one: md5 = 566a9286d7cc95df9d9eb639abfe7568 OK 2025/04/26 02:29:11 INFO : one: Copied (new) 2025/04/26 02:29:11 DEBUG : Waiting for deletions to finish 2025/04/26 02:29:12 INFO : three.txt: Moved (server-side) to: three.txt.bak 2025/04/26 02:29:12 INFO : three.txt: Moved into backup dir 2025/04/26 02:29:14 DEBUG : dst/three.txt: md5 = 23abbac6075a55503e4b383506d0534c OK 2025/04/26 02:29:15 DEBUG : one: Sizes differ (src 5 vs dst 4) 2025/04/26 02:29:15 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/26 02:29:15 DEBUG : two: Unchanged skipping 2025/04/26 02:29:15 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-datebod4zayo/dst': Waiting for checks to finish 2025/04/26 02:29:15 INFO : one.bak: Deleted 2025/04/26 02:29:16 INFO : one: Moved (server-side) to: one.bak 2025/04/26 02:29:16 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-datebod4zayo/dst': Waiting for transfers to finish 2025/04/26 02:29:17 DEBUG : one: md5 = 21d752b8697999b65175300f2353f344 OK 2025/04/26 02:29:17 INFO : one: Copied (new) 2025/04/26 02:29:17 DEBUG : Waiting for deletions to finish 2025/04/26 02:29:18 INFO : three.txt.bak: Deleted 2025/04/26 02:29:18 INFO : three.txt: Moved (server-side) to: three.txt.bak 2025/04/26 02:29:18 INFO : three.txt: Moved into backup dir 2025/04/26 02:29:21 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" 2025/04/26 02:29:21 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k" 2025/04/26 02:29:22 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "qltcak2uaegtmcoa8vijdppbp8" 2025/04/26 02:29:22 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "sk91qgsqfn0r271r2ehsaoc20c" 2025/04/26 02:29:22 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "sk91qgsqfn0r271r2ehsaoc20c" 2025/04/26 02:29:22 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "qltcak2uaegtmcoa8vijdppbp8" --- PASS: TestSyncBackupDirWithSuffix (20.74s) === RUN TestSyncBackupDirWithSuffixKeepExtension run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-datebod4zayo'", Local "Local file system at /tmp/rclone381040261", Modify Window "1ms" 2025/04/26 02:29:24 DEBUG : dst/one: md5 = 7d7d59e11804b238f1a85c1bbd0dac98 OK 2025/04/26 02:29:25 DEBUG : dst/two: md5 = fb02b2d12a11eed855fafab17e7adcac OK 2025/04/26 02:29:27 DEBUG : dst/three.txt: md5 = 36411c5269aefd67485f8577ee215d7c OK 2025/04/26 02:29:27 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-datebod4zayo/dst" 2025/04/26 02:29:27 DEBUG : Creating backend with remote "TestDrive:crypt/qbp2hfftvuk4chug66bfh86l0s445cogcmp7icnphgefaamfkchg/31u3jie661vd5p8j7rtc3hgbh0" 2025/04/26 02:29:28 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-datebod4zayo/backup" 2025/04/26 02:29:28 DEBUG : Creating backend with remote "TestDrive:crypt/qbp2hfftvuk4chug66bfh86l0s445cogcmp7icnphgefaamfkchg/1nrff024r7pq65ecp72fc28jb0" 2025/04/26 02:29:30 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/26 02:29:30 DEBUG : one: Sizes differ (src 4 vs dst 3) 2025/04/26 02:29:30 DEBUG : two: Unchanged skipping 2025/04/26 02:29:30 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-datebod4zayo/dst': Waiting for checks to finish 2025/04/26 02:29:31 INFO : one: Moved (server-side) to: one-2019-01-01 2025/04/26 02:29:31 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-datebod4zayo/dst': Waiting for transfers to finish 2025/04/26 02:29:32 DEBUG : one: md5 = b45abe02e3a745d52aa4c50997c242fc OK 2025/04/26 02:29:32 INFO : one: Copied (new) 2025/04/26 02:29:32 DEBUG : Waiting for deletions to finish 2025/04/26 02:29:33 INFO : three.txt: Moved (server-side) to: three-2019-01-01.txt 2025/04/26 02:29:33 INFO : three.txt: Moved into backup dir 2025/04/26 02:29:35 DEBUG : dst/three.txt: md5 = 4a54f03e876f442e59c3fea81fd34d8a OK 2025/04/26 02:29:36 DEBUG : one: Sizes differ (src 5 vs dst 4) 2025/04/26 02:29:36 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/26 02:29:36 DEBUG : two: Unchanged skipping 2025/04/26 02:29:36 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-datebod4zayo/dst': Waiting for checks to finish 2025/04/26 02:29:36 INFO : one-2019-01-01: Deleted 2025/04/26 02:29:37 INFO : one: Moved (server-side) to: one-2019-01-01 2025/04/26 02:29:37 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-datebod4zayo/dst': Waiting for transfers to finish 2025/04/26 02:29:38 DEBUG : one: md5 = 9227e0994509acaa827f48cc831f476c OK 2025/04/26 02:29:38 INFO : one: Copied (new) 2025/04/26 02:29:38 DEBUG : Waiting for deletions to finish 2025/04/26 02:29:39 INFO : three-2019-01-01.txt: Deleted 2025/04/26 02:29:39 INFO : three.txt: Moved (server-side) to: three-2019-01-01.txt 2025/04/26 02:29:39 INFO : three.txt: Moved into backup dir 2025/04/26 02:29:42 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" 2025/04/26 02:29:42 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k" 2025/04/26 02:29:42 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "qtq2f6qq4lgpsmj88vb7147qje3prudmtfdtr2342fth58vo9a50" 2025/04/26 02:29:42 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "jcjl1bv3ep0v8kt35lqql1co90" 2025/04/26 02:29:42 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "jcjl1bv3ep0v8kt35lqql1co90" 2025/04/26 02:29:42 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "qtq2f6qq4lgpsmj88vb7147qje3prudmtfdtr2342fth58vo9a50" --- PASS: TestSyncBackupDirWithSuffixKeepExtension (20.93s) === RUN TestSyncBackupDirSuffixOnly run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-datebod4zayo'", Local "Local file system at /tmp/rclone381040261", Modify Window "1ms" 2025/04/26 02:29:45 DEBUG : dst/one: md5 = 61fba08fe8627dfc9204b8162f4d3c34 OK 2025/04/26 02:29:46 DEBUG : dst/two: md5 = f5270cb7377f53a118fa4505b799ecf9 OK 2025/04/26 02:29:48 DEBUG : dst/three.txt: md5 = b0590cee295efec6b6bfba957fd1ace0 OK 2025/04/26 02:29:48 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-datebod4zayo/dst" 2025/04/26 02:29:48 DEBUG : Creating backend with remote "TestDrive:crypt/qbp2hfftvuk4chug66bfh86l0s445cogcmp7icnphgefaamfkchg/31u3jie661vd5p8j7rtc3hgbh0" 2025/04/26 02:29:49 DEBUG : one: Sizes differ (src 4 vs dst 3) 2025/04/26 02:29:49 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/26 02:29:49 DEBUG : two: Unchanged skipping 2025/04/26 02:29:49 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-datebod4zayo/dst': Waiting for checks to finish 2025/04/26 02:29:50 INFO : one: Moved (server-side) to: one.bak 2025/04/26 02:29:50 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-datebod4zayo/dst': Waiting for transfers to finish 2025/04/26 02:29:51 DEBUG : one: md5 = a36a1ac074e3c2de1c505aa8ecadee31 OK 2025/04/26 02:29:51 INFO : one: Copied (new) 2025/04/26 02:29:51 DEBUG : Waiting for deletions to finish 2025/04/26 02:29:52 INFO : three.txt: Moved (server-side) to: three.txt.bak 2025/04/26 02:29:52 INFO : three.txt: Moved into backup dir 2025/04/26 02:29:54 DEBUG : dst/three.txt: md5 = 91a9bcd31c79c9c837fb7b5613f347b1 OK 2025/04/26 02:29:54 DEBUG : three.txt.bak: Excluded (Path Filter) 2025/04/26 02:29:54 DEBUG : one.bak: Excluded (Path Filter) 2025/04/26 02:29:54 DEBUG : one: Sizes differ (src 5 vs dst 4) 2025/04/26 02:29:54 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-datebod4zayo/dst': Waiting for checks to finish 2025/04/26 02:29:54 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/26 02:29:54 DEBUG : two: Unchanged skipping 2025/04/26 02:29:55 INFO : one.bak: Deleted 2025/04/26 02:29:55 INFO : one: Moved (server-side) to: one.bak 2025/04/26 02:29:55 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-datebod4zayo/dst': Waiting for transfers to finish 2025/04/26 02:29:57 DEBUG : one: md5 = 65c196a54857b7f3125cfdfc7cd59174 OK 2025/04/26 02:29:57 INFO : one: Copied (new) 2025/04/26 02:29:57 DEBUG : Waiting for deletions to finish 2025/04/26 02:29:57 INFO : three.txt.bak: Deleted 2025/04/26 02:29:58 INFO : three.txt: Moved (server-side) to: three.txt.bak 2025/04/26 02:29:58 INFO : three.txt: Moved into backup dir 2025/04/26 02:30:01 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" 2025/04/26 02:30:01 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "qltcak2uaegtmcoa8vijdppbp8" 2025/04/26 02:30:01 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "sk91qgsqfn0r271r2ehsaoc20c" 2025/04/26 02:30:01 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k" 2025/04/26 02:30:01 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "sk91qgsqfn0r271r2ehsaoc20c" 2025/04/26 02:30:01 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "qltcak2uaegtmcoa8vijdppbp8" --- PASS: TestSyncBackupDirSuffixOnly (18.02s) === RUN TestSyncSuffix run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-datebod4zayo'", Local "Local file system at /tmp/rclone381040261", Modify Window "1ms" 2025/04/26 02:30:03 DEBUG : dst/one: md5 = 7d1f95f52c53bdadeeba06128e755b09 OK 2025/04/26 02:30:04 DEBUG : dst/two: md5 = af7d08577722d40606ef1f2c8cd8138e OK 2025/04/26 02:30:06 DEBUG : dst/three.txt: md5 = ef75c2a4f4fb55afcae387ae623f9c9d OK 2025/04/26 02:30:06 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-datebod4zayo/dst" 2025/04/26 02:30:06 DEBUG : Creating backend with remote "TestDrive:crypt/qbp2hfftvuk4chug66bfh86l0s445cogcmp7icnphgefaamfkchg/31u3jie661vd5p8j7rtc3hgbh0" 2025/04/26 02:30:07 DEBUG : one: Sizes differ (src 4 vs dst 3) 2025/04/26 02:30:08 INFO : one: Moved (server-side) to: one.bak 2025/04/26 02:30:09 DEBUG : one: md5 = b356bafcc387c476ade8f9593caee314 OK 2025/04/26 02:30:09 INFO : one: Copied (new) 2025/04/26 02:30:09 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/26 02:30:09 DEBUG : two: Unchanged skipping 2025/04/26 02:30:10 DEBUG : three.txt: Sizes differ (src 6 vs dst 5) 2025/04/26 02:30:10 INFO : three.txt: Moved (server-side) to: three.txt.bak 2025/04/26 02:30:11 DEBUG : three.txt: md5 = e2a01f536f0e2d35fd3c8cb4c6a55036 OK 2025/04/26 02:30:11 INFO : three.txt: Copied (new) 2025/04/26 02:30:13 DEBUG : one: Sizes differ (src 5 vs dst 4) 2025/04/26 02:30:13 INFO : one.bak: Deleted 2025/04/26 02:30:14 INFO : one: Moved (server-side) to: one.bak 2025/04/26 02:30:15 DEBUG : one: md5 = 083c603f2055cf5830b090b0cb053a9c OK 2025/04/26 02:30:15 INFO : one: Copied (new) 2025/04/26 02:30:15 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/26 02:30:15 DEBUG : two: Unchanged skipping 2025/04/26 02:30:16 DEBUG : three.txt: Sizes differ (src 19 vs dst 6) 2025/04/26 02:30:16 INFO : three.txt.bak: Deleted 2025/04/26 02:30:17 INFO : three.txt: Moved (server-side) to: three.txt.bak 2025/04/26 02:30:18 DEBUG : three.txt: md5 = 860511c8d9a6ef31a206a781215d4033 OK 2025/04/26 02:30:18 INFO : three.txt: Copied (new) 2025/04/26 02:30:21 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" 2025/04/26 02:30:21 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "tr2hj63d80ftlmvm6a952snjcc" 2025/04/26 02:30:21 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "qltcak2uaegtmcoa8vijdppbp8" 2025/04/26 02:30:21 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "qltcak2uaegtmcoa8vijdppbp8" 2025/04/26 02:30:21 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "sk91qgsqfn0r271r2ehsaoc20c" 2025/04/26 02:30:21 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "sk91qgsqfn0r271r2ehsaoc20c" 2025/04/26 02:30:21 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k" --- PASS: TestSyncSuffix (20.82s) === RUN TestSyncSuffixKeepExtension run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-datebod4zayo'", Local "Local file system at /tmp/rclone381040261", Modify Window "1ms" 2025/04/26 02:30:24 DEBUG : dst/one: md5 = 533003f1669369a46b43bb05404a4a30 OK 2025/04/26 02:30:25 DEBUG : dst/two: md5 = 4afda810212b0b19bfff6e1c64766c8c OK 2025/04/26 02:30:26 DEBUG : dst/three.txt: md5 = 4eb6b75d812db204d46589a525a6650a OK 2025/04/26 02:30:27 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-datebod4zayo/dst" 2025/04/26 02:30:27 DEBUG : Config file has changed externally - reloading 2025/04/26 02:30:27 DEBUG : Creating backend with remote "TestDrive:crypt/qbp2hfftvuk4chug66bfh86l0s445cogcmp7icnphgefaamfkchg/31u3jie661vd5p8j7rtc3hgbh0" 2025/04/26 02:30:28 DEBUG : one: Sizes differ (src 4 vs dst 3) 2025/04/26 02:30:29 INFO : one: Moved (server-side) to: one-2019-01-01 2025/04/26 02:30:30 DEBUG : one: md5 = 798cd94af390b2443bc4b90f2d8e1d2c OK 2025/04/26 02:30:30 INFO : one: Copied (new) 2025/04/26 02:30:30 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/26 02:30:30 DEBUG : two: Unchanged skipping 2025/04/26 02:30:30 DEBUG : three.txt: Sizes differ (src 6 vs dst 5) 2025/04/26 02:30:31 INFO : three.txt: Moved (server-side) to: three-2019-01-01.txt 2025/04/26 02:30:32 DEBUG : three.txt: md5 = 82acb57ef9335b8411c30bb300437685 OK 2025/04/26 02:30:32 INFO : three.txt: Copied (new) 2025/04/26 02:30:34 DEBUG : one: Sizes differ (src 5 vs dst 4) 2025/04/26 02:30:34 INFO : one-2019-01-01: Deleted 2025/04/26 02:30:35 INFO : one: Moved (server-side) to: one-2019-01-01 2025/04/26 02:30:36 DEBUG : one: md5 = d559046aaef098323c29e5b2f0a2093a OK 2025/04/26 02:30:36 INFO : one: Copied (new) 2025/04/26 02:30:36 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/26 02:30:36 DEBUG : two: Unchanged skipping 2025/04/26 02:30:36 DEBUG : three.txt: Sizes differ (src 19 vs dst 6) 2025/04/26 02:30:37 INFO : three-2019-01-01.txt: Deleted 2025/04/26 02:30:38 INFO : three.txt: Moved (server-side) to: three-2019-01-01.txt 2025/04/26 02:30:39 DEBUG : three.txt: md5 = ad55543a348f913a23d8ec2aafcfcf9b OK 2025/04/26 02:30:39 INFO : three.txt: Copied (new) 2025/04/26 02:30:42 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "tr2hj63d80ftlmvm6a952snjcc" 2025/04/26 02:30:42 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" 2025/04/26 02:30:42 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "jcjl1bv3ep0v8kt35lqql1co90" 2025/04/26 02:30:42 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "qtq2f6qq4lgpsmj88vb7147qje3prudmtfdtr2342fth58vo9a50" 2025/04/26 02:30:42 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k" 2025/04/26 02:30:42 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "jcjl1bv3ep0v8kt35lqql1co90" 2025/04/26 02:30:42 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "qtq2f6qq4lgpsmj88vb7147qje3prudmtfdtr2342fth58vo9a50" --- PASS: TestSyncSuffixKeepExtension (21.14s) === RUN TestSyncUTFNorm run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-datebod4zayo'", Local "Local file system at /tmp/rclone381040261", Modify Window "1ms" 2025/04/26 02:30:44 DEBUG : Testêé: md5 = 74d212658dbfa1d03342945a776067e1 OK 2025/04/26 02:30:45 DEBUG : Testêé: Sizes differ (src 14 vs dst 18) 2025/04/26 02:30:45 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-datebod4zayo': Waiting for checks to finish 2025/04/26 02:30:45 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-datebod4zayo': Waiting for transfers to finish 2025/04/26 02:30:46 DEBUG : Testêé: md5 = 52aeb6a13d17fc95494670b021f1bf7e OK 2025/04/26 02:30:46 INFO : Testêé: Copied (replaced existing) to: Testêé 2025/04/26 02:30:46 DEBUG : Waiting for deletions to finish --- PASS: TestSyncUTFNorm (4.09s) === RUN TestSyncImmutable run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-datebod4zayo'", Local "Local file system at /tmp/rclone381040261", Modify Window "1ms" 2025/04/26 02:30:48 DEBUG : existing: Need to transfer - File not found at Destination 2025/04/26 02:30:48 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-datebod4zayo': Waiting for checks to finish 2025/04/26 02:30:48 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-datebod4zayo': Waiting for transfers to finish 2025/04/26 02:30:49 DEBUG : existing: md5 = c5782ccd4d331ad6d5f13a8fc251dc44 OK 2025/04/26 02:30:49 INFO : existing: Copied (new) 2025/04/26 02:30:49 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-datebod4zayo'", Local "Local file system at /tmp/rclone381040261", Modify Window "1ms" 2025/04/26 02:30:50 DEBUG : existing: Sizes differ (src 8 vs dst 6) 2025/04/26 02:30:50 ERROR : existing: Source and destination exist but do not match: immutable file modified 2025/04/26 02:30:50 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-datebod4zayo': Waiting for checks to finish 2025/04/26 02:30:50 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-datebod4zayo': Waiting for transfers to finish 2025/04/26 02:30:50 ERROR : Encrypted drive 'TestCryptDrive:rclone-test-datebod4zayo': not deleting files as there were IO errors 2025/04/26 02:30:50 ERROR : Encrypted drive 'TestCryptDrive:rclone-test-datebod4zayo': not deleting directories as there were IO errors run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-datebod4zayo'", Local "Local file system at /tmp/rclone381040261", Modify Window "1ms" --- PASS: TestSyncImmutable (4.41s) === RUN TestSyncIgnoreCase run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-datebod4zayo'", Local "Local file system at /tmp/rclone381040261", Modify Window "1ms" 2025/04/26 02:30:53 DEBUG : EXISTING: md5 = efff2d09527538a050386a4abe7d68b3 OK 2025/04/26 02:30:53 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-datebod4zayo': Waiting for checks to finish 2025/04/26 02:30:53 DEBUG : existing: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/26 02:30:53 DEBUG : existing: Unchanged skipping 2025/04/26 02:30:53 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-datebod4zayo': Waiting for transfers to finish 2025/04/26 02:30:53 DEBUG : Waiting for deletions to finish 2025/04/26 02:30:53 INFO : There was nothing to transfer --- PASS: TestSyncIgnoreCase (2.66s) === RUN TestFixCase run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-datebod4zayo'", Local "Local file system at /tmp/rclone381040261", Modify Window "1ms" sync_test.go:2635: Skipping test as local or remote are case-sensitive --- SKIP: TestFixCase (0.44s) === RUN TestMaxTransfer === RUN TestMaxTransfer/Hard run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-datebod4zayo'", Local "Local file system at /tmp/rclone381040261", 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-datebod4zayo'", Local "Local file system at /tmp/rclone381040261", 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-datebod4zayo'", Local "Local file system at /tmp/rclone381040261", Modify Window "1ms" sync_test.go:2674: This test only runs on local --- PASS: TestMaxTransfer (1.28s) --- SKIP: TestMaxTransfer/Hard (0.42s) --- SKIP: TestMaxTransfer/Soft (0.44s) --- SKIP: TestMaxTransfer/Cautious (0.42s) === RUN TestSyncConcurrentDelete run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-datebod4zayo'", Local "Local file system at /tmp/rclone381040261", Modify Window "1ms" 2025/04/26 02:30:57 DEBUG : both0: md5 = 609a16ad884a30ba00c41901ea665104 OK 2025/04/26 02:30:59 DEBUG : only0: md5 = 05b51103166d32b8b6b919aedd5d340a OK 2025/04/26 02:31:00 DEBUG : both1: md5 = bb4259aea8f03a3fe31aee75299fb229 OK 2025/04/26 02:31:01 DEBUG : only1: md5 = 32ab87ad541c75b8ef116827a5bb25c2 OK 2025/04/26 02:31:03 DEBUG : both2: md5 = 1c2a20d298feefac5dc3c4e3c9aa7c7c OK 2025/04/26 02:31:04 DEBUG : only2: md5 = 70dc902bd2bc58f3240e797b5203cc8a OK 2025/04/26 02:31:05 DEBUG : both3: md5 = 689ae3352713d2ce76be38187e68de60 OK 2025/04/26 02:31:06 DEBUG : only3: md5 = 5aaf60efbc3aa708a3ffb8fc41156572 OK 2025/04/26 02:31:08 DEBUG : both4: md5 = 6f12ab4cb8bbf9061acba9fb276751c1 OK 2025/04/26 02:31:09 DEBUG : only4: md5 = 42b612100d4a7ed74c0e29a6ba567d04 OK 2025/04/26 02:31:11 DEBUG : both5: md5 = b7495e149d984b235b770ede8d9a22e3 OK 2025/04/26 02:31:12 DEBUG : only5: md5 = b50f5523f09e1010d8d1ca5b7ad5fd16 OK 2025/04/26 02:31:13 DEBUG : both6: md5 = df24ab724ac19f1602bb6131a6a56ec8 OK 2025/04/26 02:31:14 DEBUG : only6: md5 = e3f8b6e8bfbfe628e5390adfdab744e3 OK 2025/04/26 02:31:16 DEBUG : both7: md5 = 55d91e60276f95cd7c21d41b94051a7e OK 2025/04/26 02:31:17 DEBUG : only7: md5 = 0448d9d31b9d367b7b2ee14a9fa6951d OK 2025/04/26 02:31:18 DEBUG : both8: md5 = 3f88e9ad2c076b99790afceb52a28838 OK 2025/04/26 02:31:19 DEBUG : only8: md5 = 37259e0bf1f86f59c909ef48d715ea3f OK 2025/04/26 02:31:21 DEBUG : both9: md5 = 70d6299add8e563dcce3ae4a29ffc61b OK 2025/04/26 02:31:22 DEBUG : only9: md5 = d7036b6e309f1b783c26aac023a4ce90 OK 2025/04/26 02:31:23 DEBUG : both10: md5 = d703567e5085b96b193aed50811b8e11 OK 2025/04/26 02:31:24 DEBUG : only10: md5 = bf121ad8dcccf2145ab9dd7202b49f05 OK 2025/04/26 02:31:26 DEBUG : both11: md5 = 5e9d548a118bc1a0d795b1b39191b14f OK 2025/04/26 02:31:27 DEBUG : only11: md5 = 85ca902f7f778eeab8f43b98ff59d199 OK 2025/04/26 02:31:28 DEBUG : both12: md5 = aabe57ac17cb08c0248770e572e56056 OK 2025/04/26 02:31:29 DEBUG : only12: md5 = 8263d0799980b7e2276472702f031b90 OK 2025/04/26 02:31:31 DEBUG : both13: md5 = 4a4563322771dc334da802c27e126b77 OK 2025/04/26 02:31:32 DEBUG : only13: md5 = 72fa8367b607b8717ac254ccdeea2965 OK 2025/04/26 02:31:33 DEBUG : both14: md5 = dd317a58e626143a94e3e9ccb56eaa7d OK 2025/04/26 02:31:34 DEBUG : only14: md5 = 2477954ca80278226904f4ad55662c8f OK 2025/04/26 02:31:36 DEBUG : both15: md5 = 972823266f643677650d03380ae4f4bd OK 2025/04/26 02:31:37 DEBUG : only15: md5 = e8d0b4bfee6f9e903ee44371a902de83 OK 2025/04/26 02:31:38 DEBUG : both16: md5 = a6482d9cb12bd0b194205227dc6e1ee2 OK 2025/04/26 02:31:39 DEBUG : only16: md5 = a05ac84824c92e2cc87f17f753a43961 OK 2025/04/26 02:31:41 DEBUG : both17: md5 = 78d7bcc622ddcf6e3ee6dc9c7535b318 OK 2025/04/26 02:31:42 DEBUG : only17: md5 = b6473925c37a737ddb1d9c89c1812f68 OK 2025/04/26 02:31:43 DEBUG : both18: md5 = b271752858a773377ccf9c878f0a8a2e OK 2025/04/26 02:31:44 DEBUG : only18: md5 = ab2a0b75d05ccbf2d2f0de21cec9ee2f OK 2025/04/26 02:31:46 DEBUG : both19: md5 = 6b83d81c421e7488b9bb5f610e108054 OK 2025/04/26 02:31:47 DEBUG : only19: md5 = 7e92b3586741bbfe8653e69cedca42bd OK 2025/04/26 02:31:47 DEBUG : both0: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/26 02:31:47 DEBUG : both10: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/26 02:31:47 DEBUG : both1: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/26 02:31:47 DEBUG : both11: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/26 02:31:47 DEBUG : both0: Unchanged skipping 2025/04/26 02:31:47 DEBUG : both12: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/26 02:31:47 DEBUG : both12: Unchanged skipping 2025/04/26 02:31:47 DEBUG : both13: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/26 02:31:47 DEBUG : both13: Unchanged skipping 2025/04/26 02:31:47 DEBUG : both14: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/26 02:31:47 DEBUG : both14: Unchanged skipping 2025/04/26 02:31:47 DEBUG : both15: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/26 02:31:47 DEBUG : both15: Unchanged skipping 2025/04/26 02:31:47 DEBUG : both16: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/26 02:31:47 DEBUG : both16: Unchanged skipping 2025/04/26 02:31:47 DEBUG : both17: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/26 02:31:47 DEBUG : both10: Unchanged skipping 2025/04/26 02:31:47 DEBUG : both18: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/26 02:31:47 DEBUG : both1: Unchanged skipping 2025/04/26 02:31:47 DEBUG : both19: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/26 02:31:47 DEBUG : both11: Unchanged skipping 2025/04/26 02:31:47 DEBUG : both2: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/26 02:31:47 DEBUG : both2: Unchanged skipping 2025/04/26 02:31:47 DEBUG : both3: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/26 02:31:47 DEBUG : both3: Unchanged skipping 2025/04/26 02:31:47 DEBUG : both4: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/26 02:31:47 DEBUG : both4: Unchanged skipping 2025/04/26 02:31:47 DEBUG : both5: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/26 02:31:47 DEBUG : both5: Unchanged skipping 2025/04/26 02:31:47 DEBUG : both6: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/26 02:31:47 DEBUG : both6: Unchanged skipping 2025/04/26 02:31:47 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-datebod4zayo': Waiting for checks to finish 2025/04/26 02:31:47 DEBUG : both7: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/26 02:31:47 DEBUG : both19: Unchanged skipping 2025/04/26 02:31:47 DEBUG : both8: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/26 02:31:47 DEBUG : both17: Unchanged skipping 2025/04/26 02:31:47 DEBUG : both9: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/26 02:31:47 DEBUG : both9: Unchanged skipping 2025/04/26 02:31:47 DEBUG : both18: Unchanged skipping 2025/04/26 02:31:47 DEBUG : both7: Unchanged skipping 2025/04/26 02:31:47 DEBUG : both8: Unchanged skipping 2025/04/26 02:31:47 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-datebod4zayo': Waiting for transfers to finish 2025/04/26 02:31:47 DEBUG : Waiting for deletions to finish 2025/04/26 02:31:48 INFO : only14: Deleted 2025/04/26 02:31:48 INFO : only16: Deleted 2025/04/26 02:31:48 INFO : only11: Deleted 2025/04/26 02:31:48 INFO : only7: Deleted 2025/04/26 02:31:48 INFO : only13: Deleted 2025/04/26 02:31:48 INFO : only6: Deleted 2025/04/26 02:31:48 INFO : only5: Deleted 2025/04/26 02:31:48 INFO : only8: Deleted 2025/04/26 02:31:49 INFO : only10: Deleted 2025/04/26 02:31:49 INFO : only1: Deleted 2025/04/26 02:31:49 INFO : only15: Deleted 2025/04/26 02:31:49 INFO : only17: Deleted 2025/04/26 02:31:49 INFO : only19: Deleted 2025/04/26 02:31:49 INFO : only18: Deleted 2025/04/26 02:31:49 INFO : only3: Deleted 2025/04/26 02:31:49 INFO : only2: Deleted 2025/04/26 02:31:49 INFO : only0: Deleted 2025/04/26 02:31:49 INFO : only12: Deleted 2025/04/26 02:31:50 INFO : only9: Deleted 2025/04/26 02:31:50 INFO : only4: Deleted 2025/04/26 02:31:50 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-datebod4zayo'", Local "Local file system at /tmp/rclone381040261", Modify Window "1ms" --- PASS: TestSyncConcurrentDelete (63.05s) === RUN TestSyncConcurrentTruncate run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-datebod4zayo'", Local "Local file system at /tmp/rclone381040261", Modify Window "1ms" 2025/04/26 02:32:00 DEBUG : both0: md5 = 4f4ad7e73a751e1ff38c53ec3f7c7bea OK 2025/04/26 02:32:01 DEBUG : only0: md5 = b23e36d69e3866c0b79e7f77c87f2f85 OK 2025/04/26 02:32:03 DEBUG : both1: md5 = e7746ff1df69ffd8d2d6228d0b43a7ac OK 2025/04/26 02:32:04 DEBUG : only1: md5 = dfd5817caa0d1d6df02dc89ac4ef135e OK 2025/04/26 02:32:05 DEBUG : both2: md5 = 98497009d4bea844aa2116f57759cdbb OK 2025/04/26 02:32:06 DEBUG : only2: md5 = c4d39b3561a274fd952c6c7af245f074 OK 2025/04/26 02:32:08 DEBUG : both3: md5 = bb91af3eadaf9bbaacbb469b9ae788ac OK 2025/04/26 02:32:09 DEBUG : only3: md5 = f3f682171d75b61b41501299f0b9dbf9 OK 2025/04/26 02:32:10 DEBUG : both4: md5 = 2efa4ef19e64601159c15ff4514d129a OK 2025/04/26 02:32:11 DEBUG : only4: md5 = aeb6929258f5278c7bd00692cb6c99e2 OK 2025/04/26 02:32:12 DEBUG : both5: md5 = a6684b138cd540af4230182f5c332769 OK 2025/04/26 02:32:14 DEBUG : only5: md5 = 31bfb520e3a64a848bc9efc163d9baa7 OK 2025/04/26 02:32:15 DEBUG : both6: md5 = b091bd575f6ad073816843d748086f5a OK 2025/04/26 02:32:16 DEBUG : only6: md5 = 35b40747d70e5a8906dda3b99b1bafb7 OK 2025/04/26 02:32:17 DEBUG : both7: md5 = feee05854183b82e528dc79526d3233c OK 2025/04/26 02:32:19 DEBUG : only7: md5 = 52ecbeae2187df38d4a3cab01ef5723f OK 2025/04/26 02:32:20 DEBUG : both8: md5 = e7051d1f5492b15d711d3ebc36d23e2b OK 2025/04/26 02:32:22 DEBUG : only8: md5 = 79ec34a14c48f05dc1d1f9f43a1ef4f9 OK 2025/04/26 02:32:23 DEBUG : both9: md5 = a862e314c93aa7c13b8e6a61114f96e2 OK 2025/04/26 02:32:25 DEBUG : only9: md5 = c3a10f74eabda8dbd8715304361282cc OK 2025/04/26 02:32:26 DEBUG : both10: md5 = 23a5197db1482887b471f3e66bdca180 OK 2025/04/26 02:32:28 DEBUG : only10: md5 = 399d98b7d26046df67185fceabfe73fd OK 2025/04/26 02:32:29 DEBUG : both11: md5 = eb5a7e3cbc15bba231b805da0f18c34d OK 2025/04/26 02:32:30 DEBUG : only11: md5 = 81cb37ba6342fb6eceeb33bb7a3eb5f7 OK 2025/04/26 02:32:31 DEBUG : both12: md5 = a7daf660b07dc21f92eb878e66d13689 OK 2025/04/26 02:32:32 DEBUG : only12: md5 = fcd304b55de882eba6ed8c42ca7e8e28 OK 2025/04/26 02:32:34 DEBUG : both13: md5 = 26c5874c09eb82fa063b9017f0e22532 OK 2025/04/26 02:32:35 DEBUG : only13: md5 = 3085e367c44bff09e7a59a28be92c040 OK 2025/04/26 02:32:36 DEBUG : both14: md5 = b750e62c86636b84ef8264a274796660 OK 2025/04/26 02:32:37 DEBUG : only14: md5 = 135fc4f7e1a6638c36f28a4debb8796e OK 2025/04/26 02:32:39 DEBUG : both15: md5 = 1ecb3a878cd5951e2d9f32432d4229b5 OK 2025/04/26 02:32:40 DEBUG : only15: md5 = 3c6b75b924d9702c7ce366293a85bdb3 OK 2025/04/26 02:32:41 DEBUG : both16: md5 = 561adffcde4f94d851f83cbebc62f5dd OK 2025/04/26 02:32:42 DEBUG : only16: md5 = 1e64bebe1dcb776e21e9e770f965d1a6 OK 2025/04/26 02:32:44 DEBUG : both17: md5 = eb704ca218453234ec59b303394aaf28 OK 2025/04/26 02:32:45 DEBUG : only17: md5 = fcc64755896bdc39acd50e0a110c592b OK 2025/04/26 02:32:46 DEBUG : both18: md5 = e63b8203c299d6191d44ba4692611c21 OK 2025/04/26 02:32:48 DEBUG : only18: md5 = a2d78ee9942dee7421309ae267917e58 OK 2025/04/26 02:32:49 DEBUG : both19: md5 = 00a8506f0756246c2645c210d6444ef0 OK 2025/04/26 02:32:50 DEBUG : only19: md5 = 18e3949532f625937d6ad530d4da4722 OK 2025/04/26 02:32:51 DEBUG : both0: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/26 02:32:51 DEBUG : both1: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/26 02:32:51 DEBUG : both11: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/26 02:32:51 DEBUG : both10: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/26 02:32:51 DEBUG : both0: Unchanged skipping 2025/04/26 02:32:51 DEBUG : both12: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/26 02:32:51 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-datebod4zayo': Waiting for checks to finish 2025/04/26 02:32:51 DEBUG : both12: Unchanged skipping 2025/04/26 02:32:51 DEBUG : both13: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/26 02:32:51 DEBUG : both13: Unchanged skipping 2025/04/26 02:32:51 DEBUG : both14: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/26 02:32:51 DEBUG : both1: Unchanged skipping 2025/04/26 02:32:51 DEBUG : both15: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/26 02:32:51 DEBUG : both15: Unchanged skipping 2025/04/26 02:32:51 DEBUG : both16: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/26 02:32:51 DEBUG : both11: Unchanged skipping 2025/04/26 02:32:51 DEBUG : both17: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/26 02:32:51 DEBUG : both17: Unchanged skipping 2025/04/26 02:32:51 DEBUG : both18: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/26 02:32:51 DEBUG : both10: Unchanged skipping 2025/04/26 02:32:51 DEBUG : both19: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/26 02:32:51 DEBUG : both14: Unchanged skipping 2025/04/26 02:32:51 DEBUG : both2: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/26 02:32:51 DEBUG : both16: Unchanged skipping 2025/04/26 02:32:51 DEBUG : both3: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/26 02:32:51 DEBUG : both3: Unchanged skipping 2025/04/26 02:32:51 DEBUG : both4: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/26 02:32:51 DEBUG : both4: Unchanged skipping 2025/04/26 02:32:51 DEBUG : both5: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/26 02:32:51 DEBUG : both18: Unchanged skipping 2025/04/26 02:32:51 DEBUG : both6: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/26 02:32:51 DEBUG : both19: Unchanged skipping 2025/04/26 02:32:51 DEBUG : both7: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/26 02:32:51 DEBUG : both7: Unchanged skipping 2025/04/26 02:32:51 DEBUG : both8: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/26 02:32:51 DEBUG : both2: Unchanged skipping 2025/04/26 02:32:51 DEBUG : both9: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/04/26 02:32:51 DEBUG : both9: Unchanged skipping 2025/04/26 02:32:51 DEBUG : only0: Sizes differ (src 0 vs dst 6) 2025/04/26 02:32:51 DEBUG : only1: Sizes differ (src 0 vs dst 6) 2025/04/26 02:32:51 DEBUG : both5: Unchanged skipping 2025/04/26 02:32:51 DEBUG : only10: Sizes differ (src 0 vs dst 6) 2025/04/26 02:32:51 DEBUG : only11: Sizes differ (src 0 vs dst 6) 2025/04/26 02:32:51 DEBUG : both6: Unchanged skipping 2025/04/26 02:32:51 DEBUG : only12: Sizes differ (src 0 vs dst 6) 2025/04/26 02:32:51 DEBUG : only13: Sizes differ (src 0 vs dst 6) 2025/04/26 02:32:51 DEBUG : only14: Sizes differ (src 0 vs dst 6) 2025/04/26 02:32:51 DEBUG : only15: Sizes differ (src 0 vs dst 6) 2025/04/26 02:32:51 DEBUG : only16: Sizes differ (src 0 vs dst 6) 2025/04/26 02:32:51 DEBUG : only17: Sizes differ (src 0 vs dst 6) 2025/04/26 02:32:51 DEBUG : only18: Sizes differ (src 0 vs dst 6) 2025/04/26 02:32:51 DEBUG : only19: Sizes differ (src 0 vs dst 6) 2025/04/26 02:32:51 DEBUG : only2: Sizes differ (src 0 vs dst 6) 2025/04/26 02:32:51 DEBUG : only3: Sizes differ (src 0 vs dst 6) 2025/04/26 02:32:51 DEBUG : both8: Unchanged skipping 2025/04/26 02:32:51 DEBUG : only4: Sizes differ (src 0 vs dst 6) 2025/04/26 02:32:51 DEBUG : only5: Sizes differ (src 0 vs dst 6) 2025/04/26 02:32:51 DEBUG : only6: Sizes differ (src 0 vs dst 6) 2025/04/26 02:32:51 DEBUG : only7: Sizes differ (src 0 vs dst 6) 2025/04/26 02:32:51 DEBUG : only8: Sizes differ (src 0 vs dst 6) 2025/04/26 02:32:51 DEBUG : only9: Sizes differ (src 0 vs dst 6) 2025/04/26 02:32:51 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-datebod4zayo': Waiting for transfers to finish 2025/04/26 02:32:52 DEBUG : only10: md5 = f5002737954f67b5d3b59cfe642c832e OK 2025/04/26 02:32:52 INFO : only10: Copied (replaced existing) 2025/04/26 02:32:52 DEBUG : only12: md5 = 11a3f5d2aebe05d6724e1c31d055b0ab OK 2025/04/26 02:32:52 INFO : only12: Copied (replaced existing) 2025/04/26 02:32:52 DEBUG : only0: md5 = 5d02f30a639c401f4620313f3c3e6b2f OK 2025/04/26 02:32:52 INFO : only0: Copied (replaced existing) 2025/04/26 02:32:52 DEBUG : only13: md5 = 86a97f6ac27d7df1c8e3e84c3a7cb826 OK 2025/04/26 02:32:52 INFO : only13: Copied (replaced existing) 2025/04/26 02:32:53 DEBUG : only14: md5 = 05d4999160234e561dc85c052697dc98 OK 2025/04/26 02:32:53 INFO : only14: Copied (replaced existing) 2025/04/26 02:32:53 DEBUG : only16: md5 = 1b371c8cf79135579159f888bfa5c85c OK 2025/04/26 02:32:53 INFO : only16: Copied (replaced existing) 2025/04/26 02:32:53 DEBUG : only15: md5 = 1f7a791471d6d7f15c2709a4bfa3b37c OK 2025/04/26 02:32:53 INFO : only15: Copied (replaced existing) 2025/04/26 02:32:53 DEBUG : only1: md5 = 9f1b64336074b17c2696c8506b60d5a6 OK 2025/04/26 02:32:53 INFO : only1: Copied (replaced existing) 2025/04/26 02:32:54 DEBUG : only18: md5 = c72a651126bb6877a91d511f694ee419 OK 2025/04/26 02:32:54 INFO : only18: Copied (replaced existing) 2025/04/26 02:32:54 DEBUG : only2: md5 = fdd760ee9f7ca44380f490f79b368bf5 OK 2025/04/26 02:32:54 INFO : only2: Copied (replaced existing) 2025/04/26 02:32:54 DEBUG : only19: md5 = 38072e4e7e5c74e47452f62b4dc33cbd OK 2025/04/26 02:32:54 INFO : only19: Copied (replaced existing) 2025/04/26 02:32:54 DEBUG : only17: md5 = 90a208feee5df4531d3fa609acd0b39f OK 2025/04/26 02:32:54 INFO : only17: Copied (replaced existing) 2025/04/26 02:32:55 DEBUG : only5: md5 = f253a8afb5ed1ff6b7dacb41b75774d6 OK 2025/04/26 02:32:55 INFO : only5: Copied (replaced existing) 2025/04/26 02:32:55 DEBUG : only3: md5 = 33c00144bbc6eab2b79f93583c0a73e6 OK 2025/04/26 02:32:55 INFO : only3: Copied (replaced existing) 2025/04/26 02:32:55 DEBUG : only7: md5 = fd9710ba65d9b71b3df3931a95d9f52f OK 2025/04/26 02:32:55 INFO : only7: Copied (replaced existing) 2025/04/26 02:32:55 DEBUG : only4: md5 = 81b9d9381b504bd0c7f6f6792489e4fc OK 2025/04/26 02:32:55 INFO : only4: Copied (replaced existing) 2025/04/26 02:32:56 DEBUG : only6: md5 = b8da644beb03609ccc6ec5cb7f1b05a9 OK 2025/04/26 02:32:56 INFO : only6: Copied (replaced existing) 2025/04/26 02:32:56 DEBUG : only9: md5 = 5826ab9507412c8ccf7dd0271db5d727 OK 2025/04/26 02:32:56 INFO : only9: Copied (replaced existing) 2025/04/26 02:32:56 DEBUG : only11: md5 = fe1440986ab7763cff7331242d9bd90a OK 2025/04/26 02:32:56 INFO : only11: Copied (replaced existing) 2025/04/26 02:32:56 DEBUG : only8: md5 = f3f2928a34d7571ff5f596da61780346 OK 2025/04/26 02:32:56 INFO : only8: Copied (replaced existing) 2025/04/26 02:32:56 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-datebod4zayo'", Local "Local file system at /tmp/rclone381040261", Modify Window "1ms" --- PASS: TestSyncConcurrentTruncate (75.32s) === RUN TestSyncReplaceDirModTime run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-datebod4zayo'", Local "Local file system at /tmp/rclone381040261", Modify Window "1ms" 2025/04/26 02:33:14 DEBUG : empty_dir: Making directory with metadata 2025/04/26 02:33:14 INFO : empty_dir: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2025/04/26 02:33:14 DEBUG : empty_on_remote: Making directory with metadata 2025/04/26 02:33:14 INFO : empty_on_remote: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2025/04/26 02:33:14 DEBUG : empty_on_remote: Making directory with metadata 2025/04/26 02:33:15 INFO : empty_on_remote: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-datebod4zayo'", Local "Local file system at /tmp/rclone381040261", Modify Window "1ms" 2025/04/26 02:33:20 INFO : test_dir1: Set directory modification time (using DirSetModTime) 2025/04/26 02:33:20 INFO : test_dir2: Set directory modification time (using DirSetModTime) 2025/04/26 02:33:20 INFO : test_dir2/sub_dir: Set directory modification time (using DirSetModTime) 2025/04/26 02:33:20 INFO : empty_on_remote: Set directory modification time (using DirSetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-datebod4zayo'", Local "Local file system at /tmp/rclone381040261", Modify Window "1ms" 2025/04/26 02:33:26 DEBUG : heqj02jg0dcqlem7gl0500bvp0/24g2k8bseitblkmqnie1ibl2s8: Rmdir: contains trashed file: "633fmaa0qic3kv3cladnu11pto" 2025/04/26 02:33:27 DEBUG : heqj02jg0dcqlem7gl0500bvp0: Rmdir: contains trashed file: "24g2k8bseitblkmqnie1ibl2s8" 2025/04/26 02:33:27 DEBUG : gq68srrpl0nnf394bgf7dbu9kc: Rmdir: contains trashed file: "d26uovf0miqhd1mu3c9jbseq00" --- PASS: TestSyncReplaceDirModTime (15.06s) === RUN TestSyncReplaceDirModTimeWithEmptyDirs run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-datebod4zayo'", Local "Local file system at /tmp/rclone381040261", Modify Window "1ms" 2025/04/26 02:33:29 DEBUG : empty_dir: Making directory with metadata 2025/04/26 02:33:29 INFO : empty_dir: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2025/04/26 02:33:29 DEBUG : empty_on_remote: Making directory with metadata 2025/04/26 02:33:29 INFO : empty_on_remote: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2025/04/26 02:33:29 DEBUG : empty_on_remote: Making directory with metadata 2025/04/26 02:33:30 INFO : empty_on_remote: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-datebod4zayo'", Local "Local file system at /tmp/rclone381040261", Modify Window "1ms" 2025/04/26 02:33:34 INFO : test_dir1: Set directory modification time (using DirSetModTime) 2025/04/26 02:33:34 INFO : test_dir2: Set directory modification time (using DirSetModTime) 2025/04/26 02:33:34 INFO : test_dir2/sub_dir: Set directory modification time (using DirSetModTime) 2025/04/26 02:33:34 INFO : empty_on_remote: Set directory modification time (using DirSetModTime) 2025/04/26 02:33:34 INFO : empty_dir: Set directory modification time (using DirSetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-datebod4zayo'", Local "Local file system at /tmp/rclone381040261", Modify Window "1ms" 2025/04/26 02:33:42 DEBUG : heqj02jg0dcqlem7gl0500bvp0/24g2k8bseitblkmqnie1ibl2s8: Rmdir: contains trashed file: "633fmaa0qic3kv3cladnu11pto" 2025/04/26 02:33:42 DEBUG : heqj02jg0dcqlem7gl0500bvp0: Rmdir: contains trashed file: "24g2k8bseitblkmqnie1ibl2s8" 2025/04/26 02:33:43 DEBUG : gq68srrpl0nnf394bgf7dbu9kc: Rmdir: contains trashed file: "d26uovf0miqhd1mu3c9jbseq00" --- PASS: TestSyncReplaceDirModTimeWithEmptyDirs (16.17s) === RUN TestNothingToTransferWithEmptyDirs run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-datebod4zayo'", Local "Local file system at /tmp/rclone381040261", Modify Window "1ms" 2025/04/26 02:33:46 INFO : sub dir: Set directory modification time (using DirSetModTime) 2025/04/26 02:33:46 DEBUG : sub dir: Making directory with metadata 2025/04/26 02:33:46 INFO : sub dir: Made directory with metadata (mtime=2011-12-30T12:59:59Z) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-datebod4zayo'", Local "Local file system at /tmp/rclone381040261", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-datebod4zayo'", Local "Local file system at /tmp/rclone381040261", Modify Window "1ms" 2025/04/26 02:34:02 INFO : sub dir2: Set directory modification time (using DirSetModTime) 2025/04/26 02:34:03 INFO : sub dir2: Set directory modification time (using DirSetModTime) 2025/04/26 02:34:03 INFO : sub dirEmpty/sub dirEmpty2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2025/04/26 02:34:03 INFO : sub dirEmpty: Set directory modification time (using DirSetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-datebod4zayo'", Local "Local file system at /tmp/rclone381040261", Modify Window "1ms" 2025/04/26 02:34:16 DEBUG : gcsdkq814sbtppue42dpsbg8ug: Rmdir: contains trashed file: "sjuo65gk5q3r1199jselk9k9o0" 2025/04/26 02:34:17 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/37qp6d1gohacv723ij3brofbu8/i24n0ln37pa2hv8pctddeuh73o: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" 2025/04/26 02:34:17 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/37qp6d1gohacv723ij3brofbu8: Rmdir: contains trashed file: "i24n0ln37pa2hv8pctddeuh73o" 2025/04/26 02:34:18 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "37qp6d1gohacv723ij3brofbu8" 2025/04/26 02:34:18 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak" 2025/04/26 02:34:19 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak" 2025/04/26 02:34:20 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak" 2025/04/26 02:34:20 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak" 2025/04/26 02:34:21 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/4r13oncfa2rsrr82oqhsqv24ns: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" 2025/04/26 02:34:22 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc: Rmdir: contains trashed file: "4r13oncfa2rsrr82oqhsqv24ns" 2025/04/26 02:34:22 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak" 2025/04/26 02:34:22 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestNothingToTransferWithEmptyDirs (38.61s) === RUN TestNothingToTransferWithoutEmptyDirs run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-datebod4zayo'", Local "Local file system at /tmp/rclone381040261", Modify Window "1ms" 2025/04/26 02:34:24 INFO : sub dir: Set directory modification time (using DirSetModTime) 2025/04/26 02:34:24 DEBUG : sub dir: Making directory with metadata 2025/04/26 02:34:25 INFO : sub dir: Made directory with metadata (mtime=2011-12-30T12:59:59Z) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-datebod4zayo'", Local "Local file system at /tmp/rclone381040261", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-datebod4zayo'", Local "Local file system at /tmp/rclone381040261", Modify Window "1ms" 2025/04/26 02:34:45 INFO : sub dir2: Set directory modification time (using DirSetModTime) 2025/04/26 02:34:45 INFO : sub dir2: Set directory modification time (using DirSetModTime) 2025/04/26 02:34:45 INFO : sub dirEmpty/sub dirEmpty2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2025/04/26 02:34:45 INFO : sub dirEmpty: Set directory modification time (using DirSetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-datebod4zayo'", Local "Local file system at /tmp/rclone381040261", Modify Window "1ms" 2025/04/26 02:34:57 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/37qp6d1gohacv723ij3brofbu8/i24n0ln37pa2hv8pctddeuh73o: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" 2025/04/26 02:34:58 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/37qp6d1gohacv723ij3brofbu8: Rmdir: contains trashed file: "i24n0ln37pa2hv8pctddeuh73o" 2025/04/26 02:34:58 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "37qp6d1gohacv723ij3brofbu8" 2025/04/26 02:34:59 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak" 2025/04/26 02:35:00 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak" 2025/04/26 02:35:00 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak" 2025/04/26 02:35:01 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak" 2025/04/26 02:35:02 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/4r13oncfa2rsrr82oqhsqv24ns: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" 2025/04/26 02:35:02 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc: Rmdir: contains trashed file: "4r13oncfa2rsrr82oqhsqv24ns" 2025/04/26 02:35:02 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak" 2025/04/26 02:35:03 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestNothingToTransferWithoutEmptyDirs (40.61s) PASS 2025/04/26 02:35:05 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-datebod4zayo': Purge remote "./sync.test -test.v -test.timeout 1h0m0s -remote TestCryptDrive: -verbose -fast-list" - Finished OK in 14m31.816171673s (try 1/5)