"./sync.test -test.v -test.timeout 1h0m0s -remote TestCryptDrive: -verbose -fast-list" - Starting (try 1/5) 2025/01/15 03:53:21 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-wikoqah8fura" 2025/01/15 03:53:21 DEBUG : Using config file from "/home/rclone/.rclone.conf" 2025/01/15 03:53:21 DEBUG : Creating backend with remote "TestDrive:crypt/p8337uk2j9qfur1l9kur6u0mduuvg126604snkhfdbjiae9gcnag" 2025/01/15 03:53:22 DEBUG : Creating backend with remote "/tmp/rclone1597030733" === RUN TestPipe --- PASS: TestPipe (0.00s) === RUN TestPipeConcurrent --- PASS: TestPipeConcurrent (0.02s) === 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-wikoqah8fura'", Local "Local file system at /tmp/rclone1597030733", Modify Window "1ms" 2025/01/15 03:53:23 DEBUG : Added delayed dir = "sub dir", newDst= 2025/01/15 03:53:23 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2025/01/15 03:53:23 NOTICE: sub dir/hello world: Skipped copy as --dry-run is set (size 11) 2025/01/15 03:53:23 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wikoqah8fura': Waiting for checks to finish 2025/01/15 03:53:23 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wikoqah8fura': Waiting for transfers to finish 2025/01/15 03:53:23 NOTICE: sub dir: Skipped set directory modification time as --dry-run is set run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-wikoqah8fura'", Local "Local file system at /tmp/rclone1597030733", Modify Window "1ms" --- PASS: TestCopyWithDryRun (2.35s) === RUN TestCopy run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-wikoqah8fura'", Local "Local file system at /tmp/rclone1597030733", Modify Window "1ms" 2025/01/15 03:53:24 INFO : sub dir: Set directory modification time (using DirSetModTime) 2025/01/15 03:53:24 DEBUG : Added delayed dir = "sub dir", newDst= 2025/01/15 03:53:24 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2025/01/15 03:53:24 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wikoqah8fura': Waiting for checks to finish 2025/01/15 03:53:24 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wikoqah8fura': Waiting for transfers to finish 2025/01/15 03:53:27 DEBUG : sub dir/hello world: md5 = 1646d4fe84b5dbc02cbfe20e2adca576 OK 2025/01/15 03:53:27 INFO : sub dir/hello world: Copied (new) 2025/01/15 03:53:28 INFO : sub dir: Set directory modification time (using DirSetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-wikoqah8fura'", Local "Local file system at /tmp/rclone1597030733", Modify Window "1ms" 2025/01/15 03:53:30 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestCopy (6.69s) === RUN TestCopyMetadata run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-wikoqah8fura'", Local "Local file system at /tmp/rclone1597030733", Modify Window "1ms" 2025/01/15 03:53:31 DEBUG : metadata sub dir: Making directory with metadata 2025/01/15 03:53:31 INFO : metadata sub dir: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2025/01/15 03:53:31 DEBUG : empty metadata sub dir: Making directory with metadata 2025/01/15 03:53:31 INFO : empty metadata sub dir: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2025/01/15 03:53:31 DEBUG : Local file system at /tmp/rclone1597030733: File to upload is small (21 bytes), uploading instead of streaming 2025/01/15 03:53:31 DEBUG : metadata sub dir/hello metadata world: md5 = baa7a013449dbba2b1ed02b5cfb4e1a2 OK 2025/01/15 03:53:31 DEBUG : metadata sub dir/hello metadata world: Size and md5 of src and dst objects identical 2025/01/15 03:53:31 INFO : metadata sub dir: Set directory modification time (using DirSetModTime) 2025/01/15 03:53:31 DEBUG : Google drive root 'crypt/p8337uk2j9qfur1l9kur6u0mduuvg126604snkhfdbjiae9gcnag': Skipping btime metadata as can't update it on an existing file: 2025-01-15T03:53:31.218970578Z 2025/01/15 03:53:32 INFO : empty metadata sub dir: Updated directory metadata 2025/01/15 03:53:32 DEBUG : Google drive root 'crypt/p8337uk2j9qfur1l9kur6u0mduuvg126604snkhfdbjiae9gcnag': Skipping btime metadata as can't update it on an existing file: 2025-01-15T03:53:31.218970578Z 2025/01/15 03:53:33 INFO : metadata sub dir: Updated directory metadata 2025/01/15 03:53:33 DEBUG : metadata sub dir/hello metadata world: Need to transfer - File not found at Destination 2025/01/15 03:53:33 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wikoqah8fura': Waiting for checks to finish 2025/01/15 03:53:33 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wikoqah8fura': Waiting for transfers to finish 2025/01/15 03:53:35 DEBUG : metadata sub dir/hello metadata world: md5 = 99c16dcddc2de579303d9e9e622dd0e4 OK 2025/01/15 03:53:35 INFO : metadata sub dir/hello metadata world: Copied (new) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-wikoqah8fura'", Local "Local file system at /tmp/rclone1597030733", Modify Window "1ms" 2025/01/15 03:53:38 DEBUG : fg45q1rm3kh00nmmkk4m6ihmrcnel1p7551kqhjr9bk2gtd2gbf0: Rmdir: contains trashed file: "dmuvulfij81f693ur0f1vvbvq9v6iscp56daas3m51n9li5e3470" --- PASS: TestCopyMetadata (9.12s) === RUN TestCopyMetadataNoEmptyDirs run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-wikoqah8fura'", Local "Local file system at /tmp/rclone1597030733", Modify Window "1ms" 2025/01/15 03:53:40 DEBUG : metadata sub dir: Making directory with metadata 2025/01/15 03:53:40 INFO : metadata sub dir: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2025/01/15 03:53:40 DEBUG : empty metadata sub dir: Making directory with metadata 2025/01/15 03:53:40 INFO : empty metadata sub dir: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2025/01/15 03:53:40 DEBUG : Local file system at /tmp/rclone1597030733: File to upload is small (21 bytes), uploading instead of streaming 2025/01/15 03:53:40 DEBUG : metadata sub dir/hello metadata world: md5 = baa7a013449dbba2b1ed02b5cfb4e1a2 OK 2025/01/15 03:53:40 DEBUG : metadata sub dir/hello metadata world: Size and md5 of src and dst objects identical 2025/01/15 03:53:40 INFO : metadata sub dir: Set directory modification time (using DirSetModTime) 2025/01/15 03:53:40 DEBUG : Added delayed dir = "empty metadata sub dir", newDst= 2025/01/15 03:53:40 DEBUG : Added delayed dir = "metadata sub dir", newDst= 2025/01/15 03:53:40 DEBUG : metadata sub dir/hello metadata world: Need to transfer - File not found at Destination 2025/01/15 03:53:40 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wikoqah8fura': Waiting for checks to finish 2025/01/15 03:53:40 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wikoqah8fura': Waiting for transfers to finish 2025/01/15 03:53:43 DEBUG : metadata sub dir/hello metadata world: md5 = 844fcc52b0c97d046ceac137f4d60763 OK 2025/01/15 03:53:43 INFO : metadata sub dir/hello metadata world: Copied (new) 2025/01/15 03:53:43 DEBUG : Google drive root 'crypt/p8337uk2j9qfur1l9kur6u0mduuvg126604snkhfdbjiae9gcnag': Skipping btime metadata as can't update it on an existing file: 2025-01-15T03:53:40.338920204Z 2025/01/15 03:53:43 INFO : metadata sub dir: Updated directory metadata run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-wikoqah8fura'", Local "Local file system at /tmp/rclone1597030733", Modify Window "1ms" 2025/01/15 03:53:46 DEBUG : fg45q1rm3kh00nmmkk4m6ihmrcnel1p7551kqhjr9bk2gtd2gbf0: Rmdir: contains trashed file: "dmuvulfij81f693ur0f1vvbvq9v6iscp56daas3m51n9li5e3470" --- PASS: TestCopyMetadataNoEmptyDirs (7.63s) === RUN TestCopyMissingDirectory run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-wikoqah8fura'", Local "Local file system at /tmp/rclone1597030733", Modify Window "1ms" 2025/01/15 03:53:47 DEBUG : Creating backend with remote "/non-existing" 2025/01/15 03:53:48 ERROR : Local file system at /non-existing: error reading source root directory: directory not found 2025/01/15 03:53:48 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wikoqah8fura': Waiting for checks to finish 2025/01/15 03:53:48 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wikoqah8fura': Waiting for transfers to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-wikoqah8fura'", Local "Local file system at /tmp/rclone1597030733", Modify Window "1ms" --- PASS: TestCopyMissingDirectory (1.10s) === RUN TestCopyNoTraverse run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-wikoqah8fura'", Local "Local file system at /tmp/rclone1597030733", Modify Window "1ms" 2025/01/15 03:53:49 DEBUG : Added delayed dir = "sub dir", newDst= 2025/01/15 03:53:49 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2025/01/15 03:53:49 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wikoqah8fura': Waiting for checks to finish 2025/01/15 03:53:49 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wikoqah8fura': Waiting for transfers to finish 2025/01/15 03:53:52 DEBUG : sub dir/hello world: md5 = dc08e5391c23ceeb1598c4516abe47e0 OK 2025/01/15 03:53:52 INFO : sub dir/hello world: Copied (new) 2025/01/15 03:53:52 INFO : sub dir: Set directory modification time (using DirSetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-wikoqah8fura'", Local "Local file system at /tmp/rclone1597030733", Modify Window "1ms" 2025/01/15 03:53:54 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestCopyNoTraverse (6.98s) === RUN TestCopyCheckFirst run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-wikoqah8fura'", Local "Local file system at /tmp/rclone1597030733", Modify Window "1ms" 2025/01/15 03:53:56 INFO : Encrypted drive 'TestCryptDrive:rclone-test-wikoqah8fura': Running all checks before starting transfers 2025/01/15 03:53:56 DEBUG : Added delayed dir = "sub dir", newDst= 2025/01/15 03:53:56 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2025/01/15 03:53:56 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wikoqah8fura': Waiting for checks to finish 2025/01/15 03:53:56 INFO : Encrypted drive 'TestCryptDrive:rclone-test-wikoqah8fura': Checks finished, now starting transfers 2025/01/15 03:53:56 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wikoqah8fura': Waiting for transfers to finish 2025/01/15 03:53:59 DEBUG : sub dir/hello world: md5 = 1aa12686ad166d3a2b8b02847f4844ba OK 2025/01/15 03:53:59 INFO : sub dir/hello world: Copied (new) 2025/01/15 03:53:59 INFO : sub dir: Set directory modification time (using DirSetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-wikoqah8fura'", Local "Local file system at /tmp/rclone1597030733", Modify Window "1ms" 2025/01/15 03:54:01 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestCopyCheckFirst (6.97s) === RUN TestSyncNoTraverse run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-wikoqah8fura'", Local "Local file system at /tmp/rclone1597030733", Modify Window "1ms" 2025/01/15 03:54:03 ERROR : Ignoring --no-traverse with sync 2025/01/15 03:54:03 DEBUG : Added delayed dir = "sub dir", newDst= 2025/01/15 03:54:03 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2025/01/15 03:54:03 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wikoqah8fura': Waiting for checks to finish 2025/01/15 03:54:03 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wikoqah8fura': Waiting for transfers to finish 2025/01/15 03:54:06 DEBUG : sub dir/hello world: md5 = c8e13708e7794aacf03b4fac881083f1 OK 2025/01/15 03:54:06 INFO : sub dir/hello world: Copied (new) 2025/01/15 03:54:06 DEBUG : Waiting for deletions to finish 2025/01/15 03:54:06 INFO : sub dir: Set directory modification time (using DirSetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-wikoqah8fura'", Local "Local file system at /tmp/rclone1597030733", Modify Window "1ms" 2025/01/15 03:54:08 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestSyncNoTraverse (7.04s) === RUN TestCopyWithDepth run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-wikoqah8fura'", Local "Local file system at /tmp/rclone1597030733", Modify Window "1ms" 2025/01/15 03:54:10 DEBUG : hello world2: Need to transfer - File not found at Destination 2025/01/15 03:54:10 DEBUG : Added delayed dir = "sub dir", newDst= 2025/01/15 03:54:10 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wikoqah8fura': Waiting for checks to finish 2025/01/15 03:54:10 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wikoqah8fura': Waiting for transfers to finish 2025/01/15 03:54:11 DEBUG : hello world2: md5 = 9a02f9fa06db317d4ad766fa4fa45d7f OK 2025/01/15 03:54:11 INFO : hello world2: Copied (new) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-wikoqah8fura'", Local "Local file system at /tmp/rclone1597030733", Modify Window "1ms" --- PASS: TestCopyWithDepth (3.62s) === RUN TestCopyWithFilesFrom run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-wikoqah8fura'", Local "Local file system at /tmp/rclone1597030733", Modify Window "1ms" 2025/01/15 03:54:13 DEBUG : potato2: Need to transfer - File not found at Destination 2025/01/15 03:54:13 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wikoqah8fura': Waiting for checks to finish 2025/01/15 03:54:13 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wikoqah8fura': Waiting for transfers to finish 2025/01/15 03:54:15 DEBUG : potato2: md5 = 16ce91a371d407470808df2e8d3ce4ae OK 2025/01/15 03:54:15 INFO : potato2: Copied (new) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-wikoqah8fura'", Local "Local file system at /tmp/rclone1597030733", Modify Window "1ms" --- PASS: TestCopyWithFilesFrom (3.55s) === RUN TestCopyWithFilesFromAndNoTraverse run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-wikoqah8fura'", Local "Local file system at /tmp/rclone1597030733", Modify Window "1ms" 2025/01/15 03:54:17 DEBUG : potato2: Need to transfer - File not found at Destination 2025/01/15 03:54:17 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wikoqah8fura': Waiting for checks to finish 2025/01/15 03:54:17 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wikoqah8fura': Waiting for transfers to finish 2025/01/15 03:54:18 DEBUG : potato2: md5 = 36bfafc49a895755ee63e918e9540686 OK 2025/01/15 03:54:18 INFO : potato2: Copied (new) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-wikoqah8fura'", Local "Local file system at /tmp/rclone1597030733", Modify Window "1ms" --- PASS: TestCopyWithFilesFromAndNoTraverse (3.43s) === RUN TestCopyEmptyDirectories run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-wikoqah8fura'", Local "Local file system at /tmp/rclone1597030733", Modify Window "1ms" 2025/01/15 03:54:20 DEBUG : sub dir2/sub sub dir2: Making directory with metadata 2025/01/15 03:54:20 INFO : sub dir2/sub sub dir2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2025/01/15 03:54:20 INFO : sub dir2: Set directory modification time (using DirSetModTime) 2025/01/15 03:54:20 INFO : sub dir: Set directory modification time (using DirSetModTime) 2025/01/15 03:54:20 DEBUG : sub dir: Making directory with metadata 2025/01/15 03:54:21 INFO : sub dir: Made directory with metadata (mtime=2001-02-03T04:05:06.499999999Z) 2025/01/15 03:54:21 DEBUG : sub dir2: Making directory with metadata 2025/01/15 03:54:22 INFO : sub dir2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2025/01/15 03:54:22 DEBUG : sub dir2/sub sub dir2: Making directory with metadata 2025/01/15 03:54:22 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2025/01/15 03:54:23 INFO : sub dir2/sub sub dir2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2025/01/15 03:54:23 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wikoqah8fura': Waiting for checks to finish 2025/01/15 03:54:23 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wikoqah8fura': Waiting for transfers to finish 2025/01/15 03:54:24 DEBUG : sub dir/hello world: md5 = 922646612b2c5ac9920f3221c7ed5ded OK 2025/01/15 03:54:24 INFO : sub dir/hello world: Copied (new) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-wikoqah8fura'", Local "Local file system at /tmp/rclone1597030733", Modify Window "1ms" 2025/01/15 03:54:28 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc: Rmdir: contains trashed file: "cv6a9uf28ngrajena8kt5ijjn0" 2025/01/15 03:54:29 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestCopyEmptyDirectories (10.26s) === RUN TestCopyNoEmptyDirectories run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-wikoqah8fura'", Local "Local file system at /tmp/rclone1597030733", Modify Window "1ms" 2025/01/15 03:54:30 INFO : sub dir2: Making directory 2025/01/15 03:54:30 DEBUG : sub dir2/sub sub dir2: Making directory with metadata 2025/01/15 03:54:30 INFO : sub dir2/sub sub dir2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2025/01/15 03:54:31 DEBUG : Added delayed dir = "sub dir", newDst= 2025/01/15 03:54:31 DEBUG : Added delayed dir = "sub dir2", newDst= 2025/01/15 03:54:31 DEBUG : Added delayed dir = "sub dir2/sub sub dir2", newDst= 2025/01/15 03:54:31 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2025/01/15 03:54:31 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wikoqah8fura': Waiting for checks to finish 2025/01/15 03:54:31 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wikoqah8fura': Waiting for transfers to finish 2025/01/15 03:54:33 DEBUG : sub dir/hello world: md5 = ff179815a27fbc2e206e464ce76e3792 OK 2025/01/15 03:54:33 INFO : sub dir/hello world: Copied (new) 2025/01/15 03:54:34 INFO : sub dir: Set directory modification time (using DirSetModTime) 2025/01/15 03:54:35 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestCopyNoEmptyDirectories (5.85s) === RUN TestMoveEmptyDirectories run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-wikoqah8fura'", Local "Local file system at /tmp/rclone1597030733", Modify Window "1ms" 2025/01/15 03:54:36 DEBUG : sub dir2: Making directory with metadata 2025/01/15 03:54:36 INFO : sub dir2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2025/01/15 03:54:37 DEBUG : sub dir: Making directory with metadata 2025/01/15 03:54:37 INFO : sub dir: Made directory with metadata (mtime=2025-01-15T03:54:36.762606706Z) 2025/01/15 03:54:37 DEBUG : sub dir2: Making directory with metadata 2025/01/15 03:54:38 INFO : sub dir2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2025/01/15 03:54:38 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2025/01/15 03:54:38 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wikoqah8fura': Waiting for checks to finish 2025/01/15 03:54:38 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wikoqah8fura': Waiting for transfers to finish 2025/01/15 03:54:40 DEBUG : sub dir/hello world: md5 = 05b0d6ca4f6cb905aa658e663b30805c OK 2025/01/15 03:54:40 INFO : sub dir/hello world: Copied (new) 2025/01/15 03:54:40 INFO : sub dir/hello world: Deleted run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-wikoqah8fura'", Local "Local file system at /tmp/rclone1597030733", Modify Window "1ms" 2025/01/15 03:54:43 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestMoveEmptyDirectories (8.69s) === RUN TestSyncNoUpdateDirModtime run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-wikoqah8fura'", Local "Local file system at /tmp/rclone1597030733", Modify Window "1ms" 2025/01/15 03:54:45 DEBUG : sub dir no update dir modtime: Making directory with metadata 2025/01/15 03:54:45 INFO : sub dir no update dir modtime: Made directory with metadata (mtime=2001-02-03T04:05:06.499999999Z) 2025/01/15 03:54:47 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wikoqah8fura': Waiting for checks to finish 2025/01/15 03:54:47 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wikoqah8fura': Waiting for transfers to finish 2025/01/15 03:54:47 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-wikoqah8fura'", Local "Local file system at /tmp/rclone1597030733", Modify Window "1ms" --- PASS: TestSyncNoUpdateDirModtime (4.62s) === RUN TestMoveNoEmptyDirectories run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-wikoqah8fura'", Local "Local file system at /tmp/rclone1597030733", Modify Window "1ms" 2025/01/15 03:54:50 INFO : sub dir2: Making directory 2025/01/15 03:54:50 DEBUG : Added delayed dir = "sub dir", newDst= 2025/01/15 03:54:50 DEBUG : Added delayed dir = "sub dir2", newDst= 2025/01/15 03:54:50 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2025/01/15 03:54:50 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wikoqah8fura': Waiting for checks to finish 2025/01/15 03:54:50 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wikoqah8fura': Waiting for transfers to finish 2025/01/15 03:54:53 DEBUG : sub dir/hello world: md5 = b5c94940a842e11cbbfea27c35f705d5 OK 2025/01/15 03:54:53 INFO : sub dir/hello world: Copied (new) 2025/01/15 03:54:53 INFO : sub dir/hello world: Deleted 2025/01/15 03:54:53 INFO : sub dir: Set directory modification time (using DirSetModTime) 2025/01/15 03:54:55 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestMoveNoEmptyDirectories (6.97s) === RUN TestSyncEmptyDirectories run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-wikoqah8fura'", Local "Local file system at /tmp/rclone1597030733", Modify Window "1ms" 2025/01/15 03:54:57 DEBUG : sub dir2: Making directory with metadata 2025/01/15 03:54:57 INFO : sub dir2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2025/01/15 03:54:57 INFO : sub dir: Set directory modification time (using DirSetModTime) 2025/01/15 03:54:57 DEBUG : sub dir: Making directory with metadata 2025/01/15 03:54:58 INFO : sub dir: Made directory with metadata (mtime=2001-02-03T04:05:06.499999999Z) 2025/01/15 03:54:58 DEBUG : sub dir2: Making directory with metadata 2025/01/15 03:54:59 INFO : sub dir2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2025/01/15 03:54:59 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2025/01/15 03:54:59 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wikoqah8fura': Waiting for checks to finish 2025/01/15 03:54:59 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wikoqah8fura': Waiting for transfers to finish 2025/01/15 03:55:00 DEBUG : sub dir/hello world: md5 = e03e9cc98f035fde7dfee4ef835c138d OK 2025/01/15 03:55:00 INFO : sub dir/hello world: Copied (new) 2025/01/15 03:55:00 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-wikoqah8fura'", Local "Local file system at /tmp/rclone1597030733", Modify Window "1ms" 2025/01/15 03:55:04 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestSyncEmptyDirectories (8.40s) === RUN TestSyncSetDelayedModTimes run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-wikoqah8fura'", Local "Local file system at /tmp/rclone1597030733", Modify Window "1ms" sync_test.go:507: Backend doesn't have DirModTimeUpdatesOnWrite set --- SKIP: TestSyncSetDelayedModTimes (0.46s) === RUN TestSyncNoEmptyDirectories run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-wikoqah8fura'", Local "Local file system at /tmp/rclone1597030733", Modify Window "1ms" 2025/01/15 03:55:05 INFO : sub dir2: Making directory 2025/01/15 03:55:06 DEBUG : Added delayed dir = "sub dir", newDst= 2025/01/15 03:55:06 DEBUG : Added delayed dir = "sub dir2", newDst= 2025/01/15 03:55:06 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2025/01/15 03:55:06 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wikoqah8fura': Waiting for checks to finish 2025/01/15 03:55:06 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wikoqah8fura': Waiting for transfers to finish 2025/01/15 03:55:08 DEBUG : sub dir/hello world: md5 = 3f2f2e4dac0cd6fcfa86d00affb07caa OK 2025/01/15 03:55:08 INFO : sub dir/hello world: Copied (new) 2025/01/15 03:55:08 DEBUG : Waiting for deletions to finish 2025/01/15 03:55:09 INFO : sub dir: Set directory modification time (using DirSetModTime) 2025/01/15 03:55:11 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestSyncNoEmptyDirectories (6.05s) === RUN TestServerSideCopy run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-wikoqah8fura'", Local "Local file system at /tmp/rclone1597030733", Modify Window "1ms" 2025/01/15 03:55:14 DEBUG : sub dir/hello world: md5 = dd0e0d9dce487926395bcd17a371a884 OK 2025/01/15 03:55:15 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-xepafof6siro" 2025/01/15 03:55:15 DEBUG : Config file has changed externally - reloading 2025/01/15 03:55:15 DEBUG : Creating backend with remote "TestDrive:crypt/g74s3cgru9u225j1c5l3nqh7mbk3j471g520srhi1lie4jo03nvg" sync_test.go:590: Server side copy (if possible) Encrypted drive 'TestCryptDrive:rclone-test-wikoqah8fura' -> Encrypted drive 'TestCryptDrive:rclone-test-xepafof6siro' 2025/01/15 03:55:16 DEBUG : Added delayed dir = "sub dir", newDst= 2025/01/15 03:55:16 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2025/01/15 03:55:16 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-xepafof6siro': Waiting for checks to finish 2025/01/15 03:55:16 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-xepafof6siro': Waiting for transfers to finish 2025/01/15 03:55:19 INFO : sub dir/hello world: Copied (server-side copy) 2025/01/15 03:55:21 INFO : sub dir: Set directory modification time (using DirSetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-wikoqah8fura'", Local "Local file system at /tmp/rclone1597030733", Modify Window "1ms" 2025/01/15 03:55:22 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-xepafof6siro': Purge remote 2025/01/15 03:55:24 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestServerSideCopy (13.74s) === RUN TestCopyOverSelf run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-wikoqah8fura'", Local "Local file system at /tmp/rclone1597030733", Modify Window "1ms" 2025/01/15 03:55:28 DEBUG : sub dir/hello world: md5 = 9d4452f3903da65521af0d9c78eeeec7 OK 2025/01/15 03:55:29 DEBUG : Added delayed dir = "sub dir", newDst=sub dir 2025/01/15 03:55:29 DEBUG : sub dir/hello world: Sizes differ (src 17 vs dst 11) 2025/01/15 03:55:29 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wikoqah8fura': Waiting for checks to finish 2025/01/15 03:55:29 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wikoqah8fura': Waiting for transfers to finish 2025/01/15 03:55:30 DEBUG : sub dir/hello world: md5 = 5732f67b1959d53254826c743570a8bb OK 2025/01/15 03:55:30 INFO : sub dir/hello world: Copied (replaced existing) 2025/01/15 03:55:31 INFO : sub dir: Set directory modification time (using SetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-wikoqah8fura'", Local "Local file system at /tmp/rclone1597030733", Modify Window "1ms" 2025/01/15 03:55:33 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestCopyOverSelf (8.50s) === RUN TestServerSideCopyOverSelf run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-wikoqah8fura'", Local "Local file system at /tmp/rclone1597030733", Modify Window "1ms" 2025/01/15 03:55:37 DEBUG : sub dir/hello world: md5 = af76f841a5db7e9d85b4adc10d86df32 OK 2025/01/15 03:55:37 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-pisijif8zalu" 2025/01/15 03:55:37 DEBUG : Config file has changed externally - reloading 2025/01/15 03:55:37 DEBUG : Creating backend with remote "TestDrive:crypt/otgmleqemjb35fa79263j4vfc55dprkpntrsa7056q3r3n5cgrpg" sync_test.go:626: Server side copy (if possible) Encrypted drive 'TestCryptDrive:rclone-test-wikoqah8fura' -> Encrypted drive 'TestCryptDrive:rclone-test-pisijif8zalu' 2025/01/15 03:55:38 DEBUG : Added delayed dir = "sub dir", newDst= 2025/01/15 03:55:38 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2025/01/15 03:55:38 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pisijif8zalu': Waiting for checks to finish 2025/01/15 03:55:38 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pisijif8zalu': Waiting for transfers to finish 2025/01/15 03:55:42 INFO : sub dir/hello world: Copied (server-side copy) 2025/01/15 03:55:42 INFO : sub dir: Set directory modification time (using DirSetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-wikoqah8fura'", Local "Local file system at /tmp/rclone1597030733", Modify Window "1ms" 2025/01/15 03:55:44 DEBUG : sub dir/hello world: md5 = bc5080fabaaa11e1ade2a6c3dc091989 OK 2025/01/15 03:55:45 DEBUG : sub dir: Directory modification time the same (differ by 0s, within tolerance 1ms) 2025/01/15 03:55:45 DEBUG : Added delayed dir = "sub dir", newDst=sub dir 2025/01/15 03:55:45 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pisijif8zalu': Waiting for checks to finish 2025/01/15 03:55:45 DEBUG : sub dir/hello world: Sizes differ (src 17 vs dst 11) 2025/01/15 03:55:45 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pisijif8zalu': Waiting for transfers to finish 2025/01/15 03:55:47 INFO : sub dir/hello world: Copied (server-side copy) 2025/01/15 03:55:48 INFO : sub dir: Set directory modification time (using SetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-wikoqah8fura'", Local "Local file system at /tmp/rclone1597030733", Modify Window "1ms" 2025/01/15 03:55:48 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-pisijif8zalu': Purge remote 2025/01/15 03:55:50 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestServerSideCopyOverSelf (18.39s) === RUN TestMoveOverSelf run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-wikoqah8fura'", Local "Local file system at /tmp/rclone1597030733", Modify Window "1ms" 2025/01/15 03:55:55 DEBUG : sub dir/hello world: md5 = 1f135de7e4c421076964ac949207ac27 OK 2025/01/15 03:55:56 DEBUG : Added delayed dir = "sub dir", newDst=sub dir 2025/01/15 03:55:56 DEBUG : sub dir/hello world: Sizes differ (src 17 vs dst 11) 2025/01/15 03:55:56 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wikoqah8fura': Waiting for checks to finish 2025/01/15 03:55:56 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wikoqah8fura': Waiting for transfers to finish 2025/01/15 03:55:58 DEBUG : sub dir/hello world: md5 = a9c0a91cfdd6f543c4bc7d9117170675 OK 2025/01/15 03:55:58 INFO : sub dir/hello world: Copied (replaced existing) 2025/01/15 03:55:58 INFO : sub dir/hello world: Deleted 2025/01/15 03:55:58 INFO : sub dir: Set directory modification time (using SetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-wikoqah8fura'", Local "Local file system at /tmp/rclone1597030733", Modify Window "1ms" 2025/01/15 03:56:00 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestMoveOverSelf (9.28s) === RUN TestServerSideMoveOverSelf run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-wikoqah8fura'", Local "Local file system at /tmp/rclone1597030733", Modify Window "1ms" 2025/01/15 03:56:04 DEBUG : sub dir/hello world: md5 = f76de33c320dca37a6be94fe08afd9b2 OK 2025/01/15 03:56:05 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-xijowaq5xifu" 2025/01/15 03:56:05 DEBUG : Creating backend with remote "TestDrive:crypt/4bk1pcrmmu2a290v2eba2hvuga9lhsemlnlnvjs5g6e0p1t9ljs0" sync_test.go:671: Server side copy (if possible) Encrypted drive 'TestCryptDrive:rclone-test-wikoqah8fura' -> Encrypted drive 'TestCryptDrive:rclone-test-xijowaq5xifu' 2025/01/15 03:56:06 DEBUG : Added delayed dir = "sub dir", newDst= 2025/01/15 03:56:06 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2025/01/15 03:56:06 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-xijowaq5xifu': Waiting for checks to finish 2025/01/15 03:56:06 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-xijowaq5xifu': Waiting for transfers to finish 2025/01/15 03:56:10 INFO : sub dir/hello world: Copied (server-side copy) 2025/01/15 03:56:10 INFO : sub dir: Set directory modification time (using DirSetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-wikoqah8fura'", Local "Local file system at /tmp/rclone1597030733", Modify Window "1ms" 2025/01/15 03:56:12 DEBUG : sub dir/hello world: md5 = f8294650a8570c93c6712b6bc27986f0 OK 2025/01/15 03:56:13 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-xijowaq5xifu': Using server-side directory move 2025/01/15 03:56:13 INFO : Encrypted drive 'TestCryptDrive:rclone-test-xijowaq5xifu': Server side directory move failed - fallback to file moves: can't copy directory - destination already exists 2025/01/15 03:56:13 DEBUG : sub dir: Directory modification time the same (differ by 0s, within tolerance 1ms) 2025/01/15 03:56:13 DEBUG : Added delayed dir = "sub dir", newDst=sub dir 2025/01/15 03:56:13 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-xijowaq5xifu': Waiting for checks to finish 2025/01/15 03:56:13 DEBUG : sub dir/hello world: Sizes differ (src 17 vs dst 11) 2025/01/15 03:56:13 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-xijowaq5xifu': Waiting for transfers to finish 2025/01/15 03:56:14 INFO : sub dir/hello world: Deleted 2025/01/15 03:56:15 INFO : sub dir/hello world: Moved (server-side) 2025/01/15 03:56:15 INFO : sub dir: Set directory modification time (using SetModTime) 2025/01/15 03:56:18 DEBUG : sub dir/hello world: md5 = aacfcfba76fc2eb920fdc7ff0a70feec OK 2025/01/15 03:56:18 DEBUG : testing file moves 2025/01/15 03:56:19 DEBUG : sub dir: Directory modification time the same (differ by 0s, within tolerance 1ms) 2025/01/15 03:56:19 DEBUG : Added delayed dir = "sub dir", newDst=sub dir 2025/01/15 03:56:19 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-xijowaq5xifu': Waiting for checks to finish 2025/01/15 03:56:19 DEBUG : sub dir/hello world: Sizes differ (src 24 vs dst 17) 2025/01/15 03:56:19 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-xijowaq5xifu': Waiting for transfers to finish 2025/01/15 03:56:19 INFO : sub dir/hello world: Deleted 2025/01/15 03:56:20 INFO : sub dir/hello world: Moved (server-side) 2025/01/15 03:56:21 INFO : sub dir: Set directory modification time (using SetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-wikoqah8fura'", Local "Local file system at /tmp/rclone1597030733", Modify Window "1ms" 2025/01/15 03:56:22 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-xijowaq5xifu': Purge remote --- PASS: TestServerSideMoveOverSelf (23.21s) === RUN TestCopyAfterDelete run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-wikoqah8fura'", Local "Local file system at /tmp/rclone1597030733", Modify Window "1ms" 2025/01/15 03:56:27 DEBUG : sub dir/hello world: md5 = 2bfe31cf5e6ff6a8089409cf3b8f1156 OK 2025/01/15 03:56:27 ERROR : : error listing: directory not found 2025/01/15 03:56:28 INFO : Local file system at /tmp/rclone1597030733: Making directory 2025/01/15 03:56:28 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wikoqah8fura': Waiting for checks to finish 2025/01/15 03:56:28 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wikoqah8fura': Waiting for transfers to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-wikoqah8fura'", Local "Local file system at /tmp/rclone1597030733", Modify Window "1ms" 2025/01/15 03:56:30 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestCopyAfterDelete (6.68s) === RUN TestCopyRedownload run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-wikoqah8fura'", Local "Local file system at /tmp/rclone1597030733", Modify Window "1ms" 2025/01/15 03:56:34 DEBUG : sub dir/hello world: md5 = d845803e925be62f3ba23e202282484a OK 2025/01/15 03:56:35 DEBUG : Added delayed dir = "sub dir", newDst= 2025/01/15 03:56:35 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2025/01/15 03:56:35 DEBUG : Local file system at /tmp/rclone1597030733: Waiting for checks to finish 2025/01/15 03:56:35 DEBUG : Local file system at /tmp/rclone1597030733: Waiting for transfers to finish 2025/01/15 03:56:37 DEBUG : sub dir/hello world.285f0a30.partial: renamed to: sub dir/hello world 2025/01/15 03:56:37 INFO : sub dir/hello world: Copied (new) 2025/01/15 03:56:37 INFO : sub dir: Set directory modification time (using DirSetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-wikoqah8fura'", Local "Local file system at /tmp/rclone1597030733", Modify Window "1ms" 2025/01/15 03:56:38 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestCopyRedownload (8.14s) === RUN TestSyncBasedOnCheckSum run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-wikoqah8fura'", Local "Local file system at /tmp/rclone1597030733", Modify Window "1ms" 2025/01/15 03:56:40 DEBUG : check sum: Need to transfer - File not found at Destination 2025/01/15 03:56:40 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wikoqah8fura': Waiting for checks to finish 2025/01/15 03:56:40 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wikoqah8fura': Waiting for transfers to finish 2025/01/15 03:56:41 DEBUG : check sum: md5 = 498daf6d9813e99bef90272f6d4acc02 OK 2025/01/15 03:56:41 INFO : check sum: Copied (new) 2025/01/15 03:56:41 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-wikoqah8fura'", Local "Local file system at /tmp/rclone1597030733", Modify Window "1ms" 2025/01/15 03:56:42 NOTICE: Encrypted drive 'TestCryptDrive:rclone-test-wikoqah8fura': --checksum is in use but the source and destination have no hashes in common; falling back to --size-only 2025/01/15 03:56:42 DEBUG : check sum: Size of src and dst objects identical 2025/01/15 03:56:42 DEBUG : check sum: Unchanged skipping 2025/01/15 03:56:42 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wikoqah8fura': Waiting for checks to finish 2025/01/15 03:56:42 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wikoqah8fura': Waiting for transfers to finish 2025/01/15 03:56:42 DEBUG : Waiting for deletions to finish 2025/01/15 03:56:42 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-wikoqah8fura'", Local "Local file system at /tmp/rclone1597030733", Modify Window "1ms" --- PASS: TestSyncBasedOnCheckSum (4.59s) === RUN TestSyncSizeOnly run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-wikoqah8fura'", Local "Local file system at /tmp/rclone1597030733", Modify Window "1ms" 2025/01/15 03:56:44 DEBUG : sizeonly: Need to transfer - File not found at Destination 2025/01/15 03:56:44 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wikoqah8fura': Waiting for checks to finish 2025/01/15 03:56:44 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wikoqah8fura': Waiting for transfers to finish 2025/01/15 03:56:46 DEBUG : sizeonly: md5 = aadb7bf4e1f12e422887530c8c04b09c OK 2025/01/15 03:56:46 INFO : sizeonly: Copied (new) 2025/01/15 03:56:46 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-wikoqah8fura'", Local "Local file system at /tmp/rclone1597030733", Modify Window "1ms" 2025/01/15 03:56:46 DEBUG : sizeonly: Sizes identical 2025/01/15 03:56:46 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wikoqah8fura': Waiting for checks to finish 2025/01/15 03:56:46 DEBUG : sizeonly: Unchanged skipping 2025/01/15 03:56:46 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wikoqah8fura': Waiting for transfers to finish 2025/01/15 03:56:46 DEBUG : Waiting for deletions to finish 2025/01/15 03:56:46 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-wikoqah8fura'", Local "Local file system at /tmp/rclone1597030733", Modify Window "1ms" --- PASS: TestSyncSizeOnly (4.39s) === RUN TestSyncIgnoreSize run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-wikoqah8fura'", Local "Local file system at /tmp/rclone1597030733", Modify Window "1ms" 2025/01/15 03:56:49 DEBUG : ignore-size: Need to transfer - File not found at Destination 2025/01/15 03:56:49 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wikoqah8fura': Waiting for checks to finish 2025/01/15 03:56:49 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wikoqah8fura': Waiting for transfers to finish 2025/01/15 03:56:50 DEBUG : ignore-size: md5 = 6be10fb599ec361d170f58266d6e9548 OK 2025/01/15 03:56:50 INFO : ignore-size: Copied (new) 2025/01/15 03:56:50 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-wikoqah8fura'", Local "Local file system at /tmp/rclone1597030733", Modify Window "1ms" 2025/01/15 03:56:51 DEBUG : ignore-size: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/01/15 03:56:51 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wikoqah8fura': Waiting for checks to finish 2025/01/15 03:56:51 DEBUG : ignore-size: Unchanged skipping 2025/01/15 03:56:51 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wikoqah8fura': Waiting for transfers to finish 2025/01/15 03:56:51 DEBUG : Waiting for deletions to finish 2025/01/15 03:56:51 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-wikoqah8fura'", Local "Local file system at /tmp/rclone1597030733", Modify Window "1ms" --- PASS: TestSyncIgnoreSize (4.46s) === RUN TestSyncIgnoreTimes run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-wikoqah8fura'", Local "Local file system at /tmp/rclone1597030733", Modify Window "1ms" 2025/01/15 03:56:54 DEBUG : existing: md5 = cdb4c513e3e59cedff222452fe8b393a OK 2025/01/15 03:56:55 DEBUG : existing: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/01/15 03:56:55 DEBUG : existing: Unchanged skipping 2025/01/15 03:56:55 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wikoqah8fura': Waiting for checks to finish 2025/01/15 03:56:55 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wikoqah8fura': Waiting for transfers to finish 2025/01/15 03:56:55 DEBUG : Waiting for deletions to finish 2025/01/15 03:56:55 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-wikoqah8fura'", Local "Local file system at /tmp/rclone1597030733", Modify Window "1ms" 2025/01/15 03:56:55 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wikoqah8fura': Waiting for checks to finish 2025/01/15 03:56:55 DEBUG : existing: Transferring unconditionally as --ignore-times is in use 2025/01/15 03:56:55 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wikoqah8fura': Waiting for transfers to finish 2025/01/15 03:56:56 DEBUG : existing: md5 = 1f1b7b52e62f2551fe7d06d820966802 OK 2025/01/15 03:56:56 INFO : existing: Copied (replaced existing) 2025/01/15 03:56:56 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-wikoqah8fura'", Local "Local file system at /tmp/rclone1597030733", Modify Window "1ms" --- PASS: TestSyncIgnoreTimes (5.84s) === RUN TestSyncIgnoreExisting run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-wikoqah8fura'", Local "Local file system at /tmp/rclone1597030733", Modify Window "1ms" 2025/01/15 03:56:59 DEBUG : existing: Need to transfer - File not found at Destination 2025/01/15 03:56:59 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wikoqah8fura': Waiting for checks to finish 2025/01/15 03:56:59 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wikoqah8fura': Waiting for transfers to finish 2025/01/15 03:57:01 DEBUG : existing: md5 = d420359ec6cbc16f2eb69bbd85c0cede OK 2025/01/15 03:57:01 INFO : existing: Copied (new) 2025/01/15 03:57:01 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-wikoqah8fura'", Local "Local file system at /tmp/rclone1597030733", Modify Window "1ms" 2025/01/15 03:57:01 DEBUG : existing: Destination exists, skipping 2025/01/15 03:57:01 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wikoqah8fura': Waiting for checks to finish 2025/01/15 03:57:01 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wikoqah8fura': Waiting for transfers to finish 2025/01/15 03:57:01 DEBUG : Waiting for deletions to finish 2025/01/15 03:57:01 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-wikoqah8fura'", Local "Local file system at /tmp/rclone1597030733", Modify Window "1ms" --- PASS: TestSyncIgnoreExisting (4.60s) === RUN TestSyncIgnoreErrors run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-wikoqah8fura'", Local "Local file system at /tmp/rclone1597030733", Modify Window "1ms" 2025/01/15 03:57:06 DEBUG : b/potato: md5 = 3ee3462180c9923b2d64d9a5b4e6fa29 OK 2025/01/15 03:57:08 DEBUG : c/non empty space: md5 = 5cd69af1f381aaf6c89babdd9e064693 OK 2025/01/15 03:57:08 INFO : d: Making directory 2025/01/15 03:57:10 DEBUG : Added delayed dir = "a", newDst= 2025/01/15 03:57:10 DEBUG : Added delayed dir = "c", newDst=c 2025/01/15 03:57:10 DEBUG : c/non empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/01/15 03:57:10 DEBUG : a/potato2: Need to transfer - File not found at Destination 2025/01/15 03:57:10 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wikoqah8fura': Waiting for checks to finish 2025/01/15 03:57:10 DEBUG : c/non empty space: Unchanged skipping 2025/01/15 03:57:10 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wikoqah8fura': Waiting for transfers to finish 2025/01/15 03:57:13 DEBUG : a/potato2: md5 = 6301b8bb0c61c1d65451fdb2870b9ec2 OK 2025/01/15 03:57:13 INFO : a/potato2: Copied (new) 2025/01/15 03:57:13 DEBUG : Waiting for deletions to finish 2025/01/15 03:57:13 INFO : b/potato: Deleted 2025/01/15 03:57:14 INFO : a: Set directory modification time (using DirSetModTime) 2025/01/15 03:57:14 INFO : d: Removing directory 2025/01/15 03:57:15 INFO : b: Removing directory 2025/01/15 03:57:15 DEBUG : 32d8ua6196mc1r7qkfog53rkg0: Rmdir: contains trashed file: "2m507n64kafsi59v9q71r281a4" 2025/01/15 03:57:16 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wikoqah8fura': deleted 2 directories run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-wikoqah8fura'", Local "Local file system at /tmp/rclone1597030733", Modify Window "1ms" 2025/01/15 03:57:18 DEBUG : 3i9du405pfogq3ncai6pg7ouio: Rmdir: contains trashed file: "982d3pss7t5pn0il16r2foj31s" 2025/01/15 03:57:19 DEBUG : 2bsvlrk2ne1lfitm6tttcu0qt8: Rmdir: contains trashed file: "89l8renevh3mji1c8r1p7qn6tg" --- PASS: TestSyncIgnoreErrors (17.08s) === RUN TestSyncAfterChangingModtimeOnly run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-wikoqah8fura'", Local "Local file system at /tmp/rclone1597030733", Modify Window "1ms" 2025/01/15 03:57:22 DEBUG : empty space: md5 = 6934de8765f97bcb8bdea4de99fcb123 OK 2025/01/15 03:57:23 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wikoqah8fura': Waiting for checks to finish 2025/01/15 03:57:23 DEBUG : empty space: Modification times differ by -95456h54m52.624456789s: 2011-12-25 12:59:59.123456789 +0000 UTC, 2001-02-03 04:05:06.499 +0000 UTC 2025/01/15 03:57:23 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wikoqah8fura': Waiting for transfers to finish 2025/01/15 03:57:23 NOTICE: empty space: Skipped copy as --dry-run is set (size 1) 2025/01/15 03:57:23 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-wikoqah8fura'", Local "Local file system at /tmp/rclone1597030733", Modify Window "1ms" 2025/01/15 03:57:23 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wikoqah8fura': Waiting for checks to finish 2025/01/15 03:57:23 DEBUG : empty space: Modification times differ by -95456h54m52.624456789s: 2011-12-25 12:59:59.123456789 +0000 UTC, 2001-02-03 04:05:06.499 +0000 UTC 2025/01/15 03:57:23 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wikoqah8fura': Waiting for transfers to finish 2025/01/15 03:57:25 DEBUG : empty space: md5 = aa2eaac51e714dcab83d73c656ab6cbc OK 2025/01/15 03:57:25 INFO : empty space: Copied (replaced existing) 2025/01/15 03:57:25 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-wikoqah8fura'", Local "Local file system at /tmp/rclone1597030733", Modify Window "1ms" --- PASS: TestSyncAfterChangingModtimeOnly (6.45s) === RUN TestSyncAfterChangingModtimeOnlyWithNoUpdateModTime run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-wikoqah8fura'", Local "Local file system at /tmp/rclone1597030733", Modify Window "1ms" sync_test.go:1016: Can't check this if no hashes supported --- PASS: TestSyncAfterChangingModtimeOnlyWithNoUpdateModTime (0.44s) === RUN TestSyncDoesntUpdateModtime run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-wikoqah8fura'", Local "Local file system at /tmp/rclone1597030733", Modify Window "1ms" 2025/01/15 03:57:29 DEBUG : foo: md5 = 138a2c4ca5b8995b8e7dfdd7877310cd OK 2025/01/15 03:57:29 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wikoqah8fura': Waiting for checks to finish 2025/01/15 03:57:29 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/01/15 03:57:29 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wikoqah8fura': Waiting for transfers to finish 2025/01/15 03:57:31 DEBUG : foo: md5 = 38f847086c13fa84659e6bb480d78de6 OK 2025/01/15 03:57:31 INFO : foo: Copied (replaced existing) 2025/01/15 03:57:31 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-wikoqah8fura'", Local "Local file system at /tmp/rclone1597030733", Modify Window "1ms" --- PASS: TestSyncDoesntUpdateModtime (5.16s) === RUN TestSyncAfterAddingAFile run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-wikoqah8fura'", Local "Local file system at /tmp/rclone1597030733", Modify Window "1ms" 2025/01/15 03:57:34 DEBUG : empty space: md5 = d72afc42864ca1201ce25988615a5019 OK 2025/01/15 03:57:34 DEBUG : potato: Need to transfer - File not found at Destination 2025/01/15 03:57:34 DEBUG : empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/01/15 03:57:34 DEBUG : empty space: Unchanged skipping 2025/01/15 03:57:34 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wikoqah8fura': Waiting for checks to finish 2025/01/15 03:57:34 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wikoqah8fura': Waiting for transfers to finish 2025/01/15 03:57:37 DEBUG : potato: md5 = 799f9a376c7077ab8520b55096c00fe2 OK 2025/01/15 03:57:37 INFO : potato: Copied (new) 2025/01/15 03:57:37 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-wikoqah8fura'", Local "Local file system at /tmp/rclone1597030733", Modify Window "1ms" --- PASS: TestSyncAfterAddingAFile (6.82s) === RUN TestSyncAfterChangingFilesSizeOnly run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-wikoqah8fura'", Local "Local file system at /tmp/rclone1597030733", Modify Window "1ms" 2025/01/15 03:57:41 DEBUG : potato: md5 = d0519dad484706e544e2cbb02a744453 OK 2025/01/15 03:57:41 DEBUG : potato: Sizes differ (src 21 vs dst 60) 2025/01/15 03:57:41 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wikoqah8fura': Waiting for checks to finish 2025/01/15 03:57:41 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wikoqah8fura': Waiting for transfers to finish 2025/01/15 03:57:43 DEBUG : potato: md5 = e89e65ac1734aa8b4cb78379e92703d8 OK 2025/01/15 03:57:43 INFO : potato: Copied (replaced existing) 2025/01/15 03:57:43 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-wikoqah8fura'", Local "Local file system at /tmp/rclone1597030733", Modify Window "1ms" --- PASS: TestSyncAfterChangingFilesSizeOnly (5.32s) === RUN TestSyncAfterChangingContentsOnly run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-wikoqah8fura'", Local "Local file system at /tmp/rclone1597030733", Modify Window "1ms" 2025/01/15 03:57:46 DEBUG : potato: md5 = 4d18a063c5b505c97c5154e4b29383fc OK 2025/01/15 03:57:47 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wikoqah8fura': Waiting for checks to finish 2025/01/15 03:57:47 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/01/15 03:57:47 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wikoqah8fura': Waiting for transfers to finish 2025/01/15 03:57:48 DEBUG : potato: md5 = 8643832eb833fcc7a8ebd2e38bd3a3c6 OK 2025/01/15 03:57:48 INFO : potato: Copied (replaced existing) 2025/01/15 03:57:48 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-wikoqah8fura'", Local "Local file system at /tmp/rclone1597030733", Modify Window "1ms" --- PASS: TestSyncAfterChangingContentsOnly (5.58s) === RUN TestSyncAfterRemovingAFileAndAddingAFileDryRun run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-wikoqah8fura'", Local "Local file system at /tmp/rclone1597030733", Modify Window "1ms" 2025/01/15 03:57:52 DEBUG : potato: md5 = 05800a7e83b4b8a21bf85d58af6fb218 OK 2025/01/15 03:57:54 DEBUG : empty space: md5 = 1f42bbde15b8857dde47b8c16eaa6af4 OK 2025/01/15 03:57:54 DEBUG : potato2: Need to transfer - File not found at Destination 2025/01/15 03:57:54 NOTICE: potato2: Skipped copy as --dry-run is set (size 60) 2025/01/15 03:57:54 DEBUG : empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/01/15 03:57:54 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wikoqah8fura': Waiting for checks to finish 2025/01/15 03:57:54 DEBUG : empty space: Unchanged skipping 2025/01/15 03:57:54 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wikoqah8fura': Waiting for transfers to finish 2025/01/15 03:57:54 DEBUG : Waiting for deletions to finish 2025/01/15 03:57:54 NOTICE: potato: Skipped delete as --dry-run is set (size 21) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-wikoqah8fura'", Local "Local file system at /tmp/rclone1597030733", Modify Window "1ms" --- PASS: TestSyncAfterRemovingAFileAndAddingAFileDryRun (6.08s) === RUN TestSyncAfterRemovingAFileAndAddingAFile run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-wikoqah8fura'", Local "Local file system at /tmp/rclone1597030733", Modify Window "1ms" 2025/01/15 03:57:58 DEBUG : potato: md5 = 325cc883e2897b2107b7fc37c94cbfa5 OK 2025/01/15 03:58:00 DEBUG : empty space: md5 = 109ca866545afda08e811d7727ba2803 OK 2025/01/15 03:58:00 DEBUG : potato2: Need to transfer - File not found at Destination 2025/01/15 03:58:00 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wikoqah8fura': Waiting for checks to finish 2025/01/15 03:58:00 DEBUG : empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/01/15 03:58:00 DEBUG : empty space: Unchanged skipping 2025/01/15 03:58:00 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wikoqah8fura': Waiting for transfers to finish 2025/01/15 03:58:02 DEBUG : potato2: md5 = d6a7bf628416b1985efa3ba0efc2e2b8 OK 2025/01/15 03:58:02 INFO : potato2: Copied (new) 2025/01/15 03:58:02 DEBUG : Waiting for deletions to finish 2025/01/15 03:58:02 INFO : potato: Deleted run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-wikoqah8fura'", Local "Local file system at /tmp/rclone1597030733", Modify Window "1ms" --- PASS: TestSyncAfterRemovingAFileAndAddingAFile (8.21s) === RUN TestSyncAfterRemovingAFileAndAddingAFileSubDir run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-wikoqah8fura'", Local "Local file system at /tmp/rclone1597030733", Modify Window "1ms" 2025/01/15 03:58:07 DEBUG : b/potato: md5 = 42bbde948b2e705290b2318509e3f0cc OK 2025/01/15 03:58:10 DEBUG : c/non empty space: md5 = 34888dfa64fce9320ba57e8d41a05080 OK 2025/01/15 03:58:10 INFO : d: Making directory 2025/01/15 03:58:11 INFO : d/e: Making directory 2025/01/15 03:58:14 DEBUG : Added delayed dir = "a", newDst= 2025/01/15 03:58:14 DEBUG : Added delayed dir = "c", newDst=c 2025/01/15 03:58:14 DEBUG : a/potato2: Need to transfer - File not found at Destination 2025/01/15 03:58:14 DEBUG : c/non empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/01/15 03:58:14 DEBUG : c/non empty space: Unchanged skipping 2025/01/15 03:58:14 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wikoqah8fura': Waiting for checks to finish 2025/01/15 03:58:14 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wikoqah8fura': Waiting for transfers to finish 2025/01/15 03:58:16 DEBUG : a/potato2: md5 = b0ddea271d7812a3c52a23381c2b0e27 OK 2025/01/15 03:58:16 INFO : a/potato2: Copied (new) 2025/01/15 03:58:16 DEBUG : Waiting for deletions to finish 2025/01/15 03:58:17 INFO : b/potato: Deleted 2025/01/15 03:58:17 INFO : a: Set directory modification time (using DirSetModTime) 2025/01/15 03:58:17 INFO : d/e: Removing directory 2025/01/15 03:58:18 INFO : d: Removing directory 2025/01/15 03:58:18 DEBUG : ka6id8d20d3s5ktapedlphgta8: Rmdir: contains trashed file: "r8sppajuabeak3sbgj2ak8vuf8" 2025/01/15 03:58:19 INFO : b: Removing directory 2025/01/15 03:58:19 DEBUG : 32d8ua6196mc1r7qkfog53rkg0: Rmdir: contains trashed file: "2m507n64kafsi59v9q71r281a4" 2025/01/15 03:58:20 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wikoqah8fura': deleted 3 directories run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-wikoqah8fura'", Local "Local file system at /tmp/rclone1597030733", Modify Window "1ms" 2025/01/15 03:58:22 DEBUG : 3i9du405pfogq3ncai6pg7ouio: Rmdir: contains trashed file: "982d3pss7t5pn0il16r2foj31s" 2025/01/15 03:58:23 DEBUG : 2bsvlrk2ne1lfitm6tttcu0qt8: Rmdir: contains trashed file: "89l8renevh3mji1c8r1p7qn6tg" --- PASS: TestSyncAfterRemovingAFileAndAddingAFileSubDir (19.77s) === RUN TestSyncAfterRemovingAFileAndAddingAFileSubDirWithErrors run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-wikoqah8fura'", Local "Local file system at /tmp/rclone1597030733", Modify Window "1ms" 2025/01/15 03:58:27 DEBUG : b/potato: md5 = b580aeeb2fbaa70a253d2022a51dde56 OK 2025/01/15 03:58:29 DEBUG : c/non empty space: md5 = bffee976445ffa5480a3798816841d66 OK 2025/01/15 03:58:29 INFO : d: Making directory 2025/01/15 03:58:31 DEBUG : Added delayed dir = "a", newDst= 2025/01/15 03:58:31 DEBUG : Added delayed dir = "c", newDst=c 2025/01/15 03:58:31 DEBUG : c/non empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/01/15 03:58:31 DEBUG : a/potato2: Need to transfer - File not found at Destination 2025/01/15 03:58:31 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wikoqah8fura': Waiting for checks to finish 2025/01/15 03:58:31 DEBUG : c/non empty space: Unchanged skipping 2025/01/15 03:58:31 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wikoqah8fura': Waiting for transfers to finish 2025/01/15 03:58:34 DEBUG : a/potato2: md5 = 6fe8ad97777b9d98500e08c110a69c17 OK 2025/01/15 03:58:34 INFO : a/potato2: Copied (new) 2025/01/15 03:58:34 ERROR : Encrypted drive 'TestCryptDrive:rclone-test-wikoqah8fura': not deleting files as there were IO errors 2025/01/15 03:58:35 INFO : a: Set directory modification time (using DirSetModTime) 2025/01/15 03:58:35 ERROR : Encrypted drive 'TestCryptDrive:rclone-test-wikoqah8fura': not deleting directories as there were IO errors run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-wikoqah8fura'", Local "Local file system at /tmp/rclone1597030733", Modify Window "1ms" 2025/01/15 03:58:38 DEBUG : 3i9du405pfogq3ncai6pg7ouio: Rmdir: contains trashed file: "982d3pss7t5pn0il16r2foj31s" 2025/01/15 03:58:39 DEBUG : 32d8ua6196mc1r7qkfog53rkg0: Rmdir: contains trashed file: "2m507n64kafsi59v9q71r281a4" 2025/01/15 03:58:40 DEBUG : 2bsvlrk2ne1lfitm6tttcu0qt8: Rmdir: contains trashed file: "89l8renevh3mji1c8r1p7qn6tg" --- PASS: TestSyncAfterRemovingAFileAndAddingAFileSubDirWithErrors (17.19s) === RUN TestSyncDeleteAfter --- PASS: TestSyncDeleteAfter (0.00s) === RUN TestSyncDeleteDuring run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-wikoqah8fura'", Local "Local file system at /tmp/rclone1597030733", Modify Window "1ms" 2025/01/15 03:58:43 DEBUG : potato: md5 = ebc3e819d8fd0d320924679e2e0e8266 OK 2025/01/15 03:58:45 DEBUG : empty space: md5 = e7f4bbd7eb47b7a95b3453b3df6f96fc OK 2025/01/15 03:58:45 DEBUG : Waiting for deletions to finish 2025/01/15 03:58:45 DEBUG : potato2: Need to transfer - File not found at Destination 2025/01/15 03:58:45 DEBUG : empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/01/15 03:58:45 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wikoqah8fura': Waiting for checks to finish 2025/01/15 03:58:45 DEBUG : empty space: Unchanged skipping 2025/01/15 03:58:45 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wikoqah8fura': Waiting for transfers to finish 2025/01/15 03:58:46 INFO : potato: Deleted 2025/01/15 03:58:47 DEBUG : potato2: md5 = 1dfc09eb419b6f71cfc79178903dd6cf OK 2025/01/15 03:58:47 INFO : potato2: Copied (new) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-wikoqah8fura'", Local "Local file system at /tmp/rclone1597030733", Modify Window "1ms" --- PASS: TestSyncDeleteDuring (8.20s) === RUN TestSyncDeleteBefore run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-wikoqah8fura'", Local "Local file system at /tmp/rclone1597030733", Modify Window "1ms" 2025/01/15 03:58:51 DEBUG : potato: md5 = 0df168e303b25ece7061f3e5ac966d5c OK 2025/01/15 03:58:53 DEBUG : empty space: md5 = 8b39d76f361d2a0b69601fc52fd7f7b6 OK 2025/01/15 03:58:53 DEBUG : Waiting for deletions to finish 2025/01/15 03:58:53 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wikoqah8fura': Waiting for checks to finish 2025/01/15 03:58:53 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wikoqah8fura': Waiting for transfers to finish 2025/01/15 03:58:54 INFO : potato: Deleted 2025/01/15 03:58:54 DEBUG : potato2: Need to transfer - File not found at Destination 2025/01/15 03:58:54 DEBUG : empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/01/15 03:58:54 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wikoqah8fura': Waiting for checks to finish 2025/01/15 03:58:54 DEBUG : empty space: Unchanged skipping 2025/01/15 03:58:54 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wikoqah8fura': Waiting for transfers to finish 2025/01/15 03:58:56 DEBUG : potato2: md5 = 480fd3bab5458e47920ccebc4ef32f17 OK 2025/01/15 03:58:56 INFO : potato2: Copied (new) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-wikoqah8fura'", Local "Local file system at /tmp/rclone1597030733", Modify Window "1ms" --- PASS: TestSyncDeleteBefore (8.27s) === RUN TestCopyDeleteBefore run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-wikoqah8fura'", Local "Local file system at /tmp/rclone1597030733", Modify Window "1ms" 2025/01/15 03:58:59 DEBUG : potato: md5 = 1050d8b6da9196ba8315b6c717d20eb5 OK 2025/01/15 03:59:00 DEBUG : potato2: Need to transfer - File not found at Destination 2025/01/15 03:59:00 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wikoqah8fura': Waiting for checks to finish 2025/01/15 03:59:00 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wikoqah8fura': Waiting for transfers to finish 2025/01/15 03:59:02 DEBUG : potato2: md5 = d7699a01b45e153d94ba0ed1391e8c74 OK 2025/01/15 03:59:02 INFO : potato2: Copied (new) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-wikoqah8fura'", Local "Local file system at /tmp/rclone1597030733", Modify Window "1ms" --- PASS: TestCopyDeleteBefore (6.08s) === RUN TestSyncWithExclude run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-wikoqah8fura'", Local "Local file system at /tmp/rclone1597030733", Modify Window "1ms" 2025/01/15 03:59:06 DEBUG : potato2: md5 = 9f323002e9d51600c4701a0e6a2adba5 OK 2025/01/15 03:59:07 DEBUG : empty space: md5 = e8b866cf938d07876ca60b84dbbf9e01 OK 2025/01/15 03:59:08 DEBUG : enormous: Excluded (Size Filter) 2025/01/15 03:59:08 DEBUG : enormous: Excluded 2025/01/15 03:59:08 DEBUG : potato2: Excluded (Size Filter) 2025/01/15 03:59:08 DEBUG : potato2: Excluded 2025/01/15 03:59:08 DEBUG : potato2: Excluded (Size Filter) 2025/01/15 03:59:08 DEBUG : empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/01/15 03:59:08 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wikoqah8fura': Waiting for checks to finish 2025/01/15 03:59:08 DEBUG : empty space: Unchanged skipping 2025/01/15 03:59:08 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wikoqah8fura': Waiting for transfers to finish 2025/01/15 03:59:08 DEBUG : Waiting for deletions to finish 2025/01/15 03:59:08 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-wikoqah8fura'", Local "Local file system at /tmp/rclone1597030733", Modify Window "1ms" 2025/01/15 03:59:08 DEBUG : enormous: Excluded (Size Filter) 2025/01/15 03:59:08 DEBUG : enormous: Excluded 2025/01/15 03:59:08 DEBUG : potato2: Excluded (Size Filter) 2025/01/15 03:59:08 DEBUG : potato2: Excluded 2025/01/15 03:59:09 DEBUG : potato2: Excluded (Size Filter) 2025/01/15 03:59:09 DEBUG : empty space: Size and modification time the same (differ by 456.789µs, within tolerance 1ms) 2025/01/15 03:59:09 DEBUG : empty space: Unchanged skipping 2025/01/15 03:59:09 DEBUG : Local file system at /tmp/rclone1597030733: Waiting for checks to finish 2025/01/15 03:59:09 DEBUG : Local file system at /tmp/rclone1597030733: Waiting for transfers to finish 2025/01/15 03:59:09 DEBUG : Waiting for deletions to finish 2025/01/15 03:59:09 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-wikoqah8fura'", Local "Local file system at /tmp/rclone1597030733", Modify Window "1ms" --- PASS: TestSyncWithExclude (7.08s) === RUN TestSyncWithExcludeAndDeleteExcluded run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-wikoqah8fura'", Local "Local file system at /tmp/rclone1597030733", Modify Window "1ms" 2025/01/15 03:59:13 DEBUG : potato2: md5 = 58e1c1ba83255f44ebf230f137804ddc OK 2025/01/15 03:59:15 DEBUG : empty space: md5 = 0bec769ea21ea6f206fbb3645982a247 OK 2025/01/15 03:59:16 DEBUG : enormous: md5 = ec7743d28f7dcd90973bcd22a0311167 OK 2025/01/15 03:59:16 DEBUG : enormous: Excluded (Size Filter) 2025/01/15 03:59:16 DEBUG : enormous: Excluded 2025/01/15 03:59:16 DEBUG : potato2: Excluded (Size Filter) 2025/01/15 03:59:16 DEBUG : potato2: Excluded 2025/01/15 03:59:17 DEBUG : empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/01/15 03:59:17 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wikoqah8fura': Waiting for checks to finish 2025/01/15 03:59:17 DEBUG : empty space: Unchanged skipping 2025/01/15 03:59:17 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wikoqah8fura': Waiting for transfers to finish 2025/01/15 03:59:17 DEBUG : Waiting for deletions to finish 2025/01/15 03:59:17 INFO : potato2: Deleted 2025/01/15 03:59:17 INFO : enormous: Deleted 2025/01/15 03:59:17 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-wikoqah8fura'", Local "Local file system at /tmp/rclone1597030733", Modify Window "1ms" 2025/01/15 03:59:18 DEBUG : Local file system at /tmp/rclone1597030733: Waiting for checks to finish 2025/01/15 03:59:18 DEBUG : empty space: Size and modification time the same (differ by 456.789µs, within tolerance 1ms) 2025/01/15 03:59:18 DEBUG : empty space: Unchanged skipping 2025/01/15 03:59:18 DEBUG : Local file system at /tmp/rclone1597030733: Waiting for transfers to finish 2025/01/15 03:59:18 DEBUG : Waiting for deletions to finish 2025/01/15 03:59:18 INFO : enormous: Deleted 2025/01/15 03:59:18 INFO : potato2: Deleted 2025/01/15 03:59:18 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-wikoqah8fura'", Local "Local file system at /tmp/rclone1597030733", Modify Window "1ms" --- PASS: TestSyncWithExcludeAndDeleteExcluded (8.78s) === RUN TestSyncWithUpdateOlder run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-wikoqah8fura'", Local "Local file system at /tmp/rclone1597030733", Modify Window "1ms" 2025/01/15 03:59:21 DEBUG : one: md5 = 358fa516d40e7231ea882f7c7d2a9083 OK 2025/01/15 03:59:23 DEBUG : two: md5 = 250d3d252e26009baf9c340b64947796 OK 2025/01/15 03:59:25 DEBUG : three: md5 = f98d54b1ebe79783eb8deb19d45084ad OK 2025/01/15 03:59:27 DEBUG : four: md5 = 644cfcb7a1463e692e9887c20b1d0c75 OK 2025/01/15 03:59:27 DEBUG : five: Need to transfer - File not found at Destination 2025/01/15 03:59:27 DEBUG : one: Destination is newer than source, skipping 2025/01/15 03:59:27 DEBUG : three: Sizes identical 2025/01/15 03:59:27 DEBUG : four: Sizes differ (src 4 vs dst 8) 2025/01/15 03:59:27 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wikoqah8fura': Waiting for checks to finish 2025/01/15 03:59:27 DEBUG : three: Destination mod time is within 1s of source and files identical, skipping 2025/01/15 03:59:27 DEBUG : four: Destination mod time is within 1s of source but files differ, transferring 2025/01/15 03:59:27 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wikoqah8fura': Waiting for transfers to finish 2025/01/15 03:59:28 DEBUG : two: md5 = 3142225f8e2ca7661b81249cb6872cee OK 2025/01/15 03:59:28 INFO : two: Copied (replaced existing) 2025/01/15 03:59:29 DEBUG : four: md5 = 103ec0cf282619b9d51edcc9158a04a7 OK 2025/01/15 03:59:29 INFO : four: Copied (replaced existing) 2025/01/15 03:59:29 DEBUG : five: md5 = c36631125aa74df6e1abd87e07db904c OK 2025/01/15 03:59:29 INFO : five: Copied (new) 2025/01/15 03:59:29 DEBUG : Waiting for deletions to finish sync_test.go:1449: Skip test with --checksum as no hashes supported --- PASS: TestSyncWithUpdateOlder (12.42s) === RUN TestSyncWithMaxDuration === RUN TestSyncWithMaxDuration/Hard sync_test.go:1466: Skipping test on non local remote === RUN TestSyncWithMaxDuration/Soft sync_test.go:1466: Skipping test on non local remote --- PASS: TestSyncWithMaxDuration (0.00s) --- SKIP: TestSyncWithMaxDuration/Hard (0.00s) --- SKIP: TestSyncWithMaxDuration/Soft (0.00s) === RUN TestSyncWithTrackRenames run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-wikoqah8fura'", Local "Local file system at /tmp/rclone1597030733", Modify Window "1ms" sync_test.go:1538: Can track renames: false 2025/01/15 03:59:32 ERROR : Encrypted drive 'TestCryptDrive:rclone-test-wikoqah8fura': Ignoring --track-renames as the source and destination do not have a common hash 2025/01/15 03:59:32 DEBUG : potato: Need to transfer - File not found at Destination 2025/01/15 03:59:32 DEBUG : yam: Need to transfer - File not found at Destination 2025/01/15 03:59:32 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wikoqah8fura': Waiting for checks to finish 2025/01/15 03:59:32 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wikoqah8fura': Waiting for transfers to finish 2025/01/15 03:59:34 DEBUG : potato: md5 = ca88c65952309d4a5c69fe8b6db05c54 OK 2025/01/15 03:59:34 INFO : potato: Copied (new) 2025/01/15 03:59:34 DEBUG : yam: md5 = f77bb8185c77c6a2960484e36bc0b43a OK 2025/01/15 03:59:34 INFO : yam: Copied (new) 2025/01/15 03:59:34 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-wikoqah8fura'", Local "Local file system at /tmp/rclone1597030733", Modify Window "1ms" 2025/01/15 03:59:34 ERROR : Encrypted drive 'TestCryptDrive:rclone-test-wikoqah8fura': Ignoring --track-renames as the source and destination do not have a common hash 2025/01/15 03:59:35 DEBUG : yaml: Need to transfer - File not found at Destination 2025/01/15 03:59:35 DEBUG : potato: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/01/15 03:59:35 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wikoqah8fura': Waiting for checks to finish 2025/01/15 03:59:35 DEBUG : potato: Unchanged skipping 2025/01/15 03:59:35 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wikoqah8fura': Waiting for transfers to finish 2025/01/15 03:59:36 DEBUG : yaml: md5 = ddb0997f420dd2b42f0ad91c2b72ccdb OK 2025/01/15 03:59:36 INFO : yaml: Copied (new) 2025/01/15 03:59:36 DEBUG : Waiting for deletions to finish 2025/01/15 03:59:37 INFO : yam: Deleted run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-wikoqah8fura'", Local "Local file system at /tmp/rclone1597030733", Modify Window "1ms" --- PASS: TestSyncWithTrackRenames (7.39s) === RUN TestParseRenamesStrategyModtime --- PASS: TestParseRenamesStrategyModtime (0.00s) === RUN TestRenamesStrategyModtime --- PASS: TestRenamesStrategyModtime (0.00s) === RUN TestSyncWithTrackRenamesStrategyModtime run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-wikoqah8fura'", Local "Local file system at /tmp/rclone1597030733", Modify Window "1ms" sync_test.go:1610: Can track renames: true 2025/01/15 03:59:40 INFO : Encrypted drive 'TestCryptDrive:rclone-test-wikoqah8fura': Making map for --track-renames 2025/01/15 03:59:40 INFO : Encrypted drive 'TestCryptDrive:rclone-test-wikoqah8fura': Finished making map for --track-renames 2025/01/15 03:59:40 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wikoqah8fura': Waiting for checks to finish 2025/01/15 03:59:40 DEBUG : potato: Need to transfer - No matching file found at Destination 2025/01/15 03:59:40 DEBUG : yam: Need to transfer - No matching file found at Destination 2025/01/15 03:59:40 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wikoqah8fura': Waiting for renames to finish 2025/01/15 03:59:40 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wikoqah8fura': Waiting for transfers to finish 2025/01/15 03:59:41 DEBUG : potato: md5 = 8db0946025f64a9c713748c91feb3158 OK 2025/01/15 03:59:41 INFO : potato: Copied (new) 2025/01/15 03:59:42 DEBUG : yam: md5 = ff0d0629ae118c39159ddaf647e652b4 OK 2025/01/15 03:59:42 INFO : yam: Copied (new) 2025/01/15 03:59:42 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-wikoqah8fura'", Local "Local file system at /tmp/rclone1597030733", Modify Window "1ms" 2025/01/15 03:59:42 DEBUG : potato: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/01/15 03:59:42 INFO : Encrypted drive 'TestCryptDrive:rclone-test-wikoqah8fura': Making map for --track-renames 2025/01/15 03:59:42 INFO : Encrypted drive 'TestCryptDrive:rclone-test-wikoqah8fura': Finished making map for --track-renames 2025/01/15 03:59:42 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wikoqah8fura': Waiting for checks to finish 2025/01/15 03:59:42 DEBUG : potato: Unchanged skipping 2025/01/15 03:59:42 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wikoqah8fura': Waiting for renames to finish 2025/01/15 03:59:43 INFO : yam: Moved (server-side) to: yaml 2025/01/15 03:59:43 INFO : yaml: Renamed from "yam" 2025/01/15 03:59:43 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wikoqah8fura': Waiting for transfers to finish 2025/01/15 03:59:43 DEBUG : Waiting for deletions to finish 2025/01/15 03:59:43 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-wikoqah8fura'", Local "Local file system at /tmp/rclone1597030733", Modify Window "1ms" --- PASS: TestSyncWithTrackRenamesStrategyModtime (6.18s) === RUN TestSyncWithTrackRenamesStrategyLeaf run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-wikoqah8fura'", Local "Local file system at /tmp/rclone1597030733", Modify Window "1ms" sync_test.go:1649: Can track renames: true 2025/01/15 03:59:46 DEBUG : Added delayed dir = "sub", newDst= 2025/01/15 03:59:46 INFO : Encrypted drive 'TestCryptDrive:rclone-test-wikoqah8fura': Making map for --track-renames 2025/01/15 03:59:46 INFO : Encrypted drive 'TestCryptDrive:rclone-test-wikoqah8fura': Finished making map for --track-renames 2025/01/15 03:59:46 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wikoqah8fura': Waiting for checks to finish 2025/01/15 03:59:46 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wikoqah8fura': Waiting for renames to finish 2025/01/15 03:59:46 DEBUG : potato: Need to transfer - No matching file found at Destination 2025/01/15 03:59:46 DEBUG : sub/yam: Need to transfer - No matching file found at Destination 2025/01/15 03:59:46 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wikoqah8fura': Waiting for transfers to finish 2025/01/15 03:59:49 DEBUG : potato: md5 = 5f65319eac060ce3b3983475703ec2bb OK 2025/01/15 03:59:49 INFO : potato: Copied (new) 2025/01/15 03:59:49 DEBUG : sub/yam: md5 = 9caaff8cf331d2e5ad1db97f001a10da OK 2025/01/15 03:59:49 INFO : sub/yam: Copied (new) 2025/01/15 03:59:49 DEBUG : Waiting for deletions to finish 2025/01/15 03:59:49 INFO : sub: Set directory modification time (using DirSetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-wikoqah8fura'", Local "Local file system at /tmp/rclone1597030733", Modify Window "1ms" 2025/01/15 03:59:50 DEBUG : Added delayed dir = "sub", newDst=sub 2025/01/15 03:59:50 DEBUG : potato: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/01/15 03:59:50 DEBUG : potato: Unchanged skipping 2025/01/15 03:59:50 INFO : Encrypted drive 'TestCryptDrive:rclone-test-wikoqah8fura': Making map for --track-renames 2025/01/15 03:59:50 INFO : Encrypted drive 'TestCryptDrive:rclone-test-wikoqah8fura': Finished making map for --track-renames 2025/01/15 03:59:50 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wikoqah8fura': Waiting for checks to finish 2025/01/15 03:59:50 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wikoqah8fura': Waiting for renames to finish 2025/01/15 03:59:52 INFO : sub/yam: Moved (server-side) to: yam 2025/01/15 03:59:52 INFO : yam: Renamed from "sub/yam" 2025/01/15 03:59:52 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wikoqah8fura': Waiting for transfers to finish 2025/01/15 03:59:52 DEBUG : Waiting for deletions to finish 2025/01/15 03:59:52 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-wikoqah8fura'", Local "Local file system at /tmp/rclone1597030733", Modify Window "1ms" --- PASS: TestSyncWithTrackRenamesStrategyLeaf (9.68s) === RUN TestServerSideMoveLocal run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-wikoqah8fura'", Local "Local file system at /tmp/rclone1597030733", Modify Window "1ms" 2025/01/15 03:59:55 DEBUG : Creating backend with remote "/tmp/rclone1597030733/dir1" 2025/01/15 03:59:55 DEBUG : Creating backend with remote "/tmp/rclone1597030733/dir2" 2025/01/15 03:59:55 DEBUG : Local file system at /tmp/rclone1597030733/dir2: Using server-side directory move 2025/01/15 03:59:55 INFO : Local file system at /tmp/rclone1597030733/dir2: Server side directory move failed - fallback to file moves: can't copy directory - destination already exists 2025/01/15 03:59:55 DEBUG : file1.txt: Need to transfer - File not found at Destination 2025/01/15 03:59:55 INFO : file1.txt: Moved (server-side) 2025/01/15 03:59:55 DEBUG : Local file system at /tmp/rclone1597030733/dir2: Waiting for checks to finish 2025/01/15 03:59:55 DEBUG : Local file system at /tmp/rclone1597030733/dir2: Waiting for transfers to finish --- PASS: TestServerSideMoveLocal (0.45s) === RUN TestMoveWithDeleteEmptySrcDirs run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-wikoqah8fura'", Local "Local file system at /tmp/rclone1597030733", Modify Window "1ms" 2025/01/15 03:59:56 DEBUG : Added delayed dir = "nested", newDst= 2025/01/15 03:59:56 DEBUG : Added delayed dir = "sub dir", newDst= 2025/01/15 03:59:56 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2025/01/15 03:59:56 DEBUG : Added delayed dir = "nested/sub dir", newDst= 2025/01/15 03:59:56 DEBUG : nested/sub dir/file: Need to transfer - File not found at Destination 2025/01/15 03:59:56 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wikoqah8fura': Waiting for checks to finish 2025/01/15 03:59:56 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wikoqah8fura': Waiting for transfers to finish 2025/01/15 03:59:59 DEBUG : sub dir/hello world: md5 = 9daab4c243f92f7f61343812193aa7a1 OK 2025/01/15 03:59:59 INFO : sub dir/hello world: Copied (new) 2025/01/15 03:59:59 INFO : sub dir/hello world: Deleted 2025/01/15 04:00:01 DEBUG : nested/sub dir/file: md5 = af2b3315cec0ecef1c922660f2653256 OK 2025/01/15 04:00:01 INFO : nested/sub dir/file: Copied (new) 2025/01/15 04:00:01 INFO : nested/sub dir/file: Deleted 2025/01/15 04:00:01 INFO : nested/sub dir: Set directory modification time (using DirSetModTime) 2025/01/15 04:00:02 INFO : nested: Set directory modification time (using DirSetModTime) 2025/01/15 04:00:02 INFO : sub dir: Set directory modification time (using DirSetModTime) 2025/01/15 04:00:02 INFO : sub dir: Removing directory 2025/01/15 04:00:02 INFO : nested/sub dir: Removing directory 2025/01/15 04:00:02 INFO : nested: Removing directory 2025/01/15 04:00:02 DEBUG : Local file system at /tmp/rclone1597030733: deleted 3 directories run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-wikoqah8fura'", Local "Local file system at /tmp/rclone1597030733", Modify Window "1ms" 2025/01/15 04:00:05 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" 2025/01/15 04:00:06 DEBUG : 37qp6d1gohacv723ij3brofbu8/14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "ftp4kuv8se7tqduu6pmmcvjsmk" 2025/01/15 04:00:07 DEBUG : 37qp6d1gohacv723ij3brofbu8: Rmdir: contains trashed file: "14begaa36ih249fgrnfk6nulg0" --- PASS: TestMoveWithDeleteEmptySrcDirs (12.23s) === RUN TestMoveWithoutDeleteEmptySrcDirs run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-wikoqah8fura'", Local "Local file system at /tmp/rclone1597030733", Modify Window "1ms" 2025/01/15 04:00:08 DEBUG : Added delayed dir = "nested", newDst= 2025/01/15 04:00:08 DEBUG : Added delayed dir = "sub dir", newDst= 2025/01/15 04:00:08 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2025/01/15 04:00:08 DEBUG : Added delayed dir = "nested/sub dir", newDst= 2025/01/15 04:00:08 DEBUG : nested/sub dir/file: Need to transfer - File not found at Destination 2025/01/15 04:00:08 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wikoqah8fura': Waiting for checks to finish 2025/01/15 04:00:08 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wikoqah8fura': Waiting for transfers to finish 2025/01/15 04:00:11 DEBUG : sub dir/hello world: md5 = 668d3fb80c940e19f284fa9d17640acb OK 2025/01/15 04:00:11 INFO : sub dir/hello world: Copied (new) 2025/01/15 04:00:11 INFO : sub dir/hello world: Deleted 2025/01/15 04:00:13 DEBUG : nested/sub dir/file: md5 = c50ba8e5110216b3bd8a622aa114af51 OK 2025/01/15 04:00:13 INFO : nested/sub dir/file: Copied (new) 2025/01/15 04:00:13 INFO : nested/sub dir/file: Deleted 2025/01/15 04:00:14 INFO : nested/sub dir: Set directory modification time (using DirSetModTime) 2025/01/15 04:00:14 INFO : nested: Set directory modification time (using DirSetModTime) 2025/01/15 04:00:14 INFO : sub dir: Set directory modification time (using DirSetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-wikoqah8fura'", Local "Local file system at /tmp/rclone1597030733", Modify Window "1ms" 2025/01/15 04:00:17 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" 2025/01/15 04:00:18 DEBUG : 37qp6d1gohacv723ij3brofbu8/14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "ftp4kuv8se7tqduu6pmmcvjsmk" 2025/01/15 04:00:19 DEBUG : 37qp6d1gohacv723ij3brofbu8: Rmdir: contains trashed file: "14begaa36ih249fgrnfk6nulg0" --- PASS: TestMoveWithoutDeleteEmptySrcDirs (11.76s) === RUN TestMoveWithIgnoreExisting run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-wikoqah8fura'", Local "Local file system at /tmp/rclone1597030733", Modify Window "1ms" 2025/01/15 04:00:20 DEBUG : existing: Need to transfer - File not found at Destination 2025/01/15 04:00:20 DEBUG : existing-b: Need to transfer - File not found at Destination 2025/01/15 04:00:20 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wikoqah8fura': Waiting for checks to finish 2025/01/15 04:00:20 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wikoqah8fura': Waiting for transfers to finish 2025/01/15 04:00:22 DEBUG : existing: md5 = b1e035686298cf7943f6e217dc2aab1c OK 2025/01/15 04:00:22 INFO : existing: Copied (new) 2025/01/15 04:00:22 INFO : existing: Deleted 2025/01/15 04:00:22 DEBUG : existing-b: md5 = 2004aa2babab2bedc12ee4fec78178c6 OK 2025/01/15 04:00:22 INFO : existing-b: Copied (new) 2025/01/15 04:00:22 INFO : existing-b: Deleted 2025/01/15 04:00:22 DEBUG : existing: Destination exists, skipping 2025/01/15 04:00:22 DEBUG : existing: Not removing source file as destination file exists and --ignore-existing is set 2025/01/15 04:00:22 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wikoqah8fura': Waiting for checks to finish 2025/01/15 04:00:22 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wikoqah8fura': Waiting for transfers to finish 2025/01/15 04:00:22 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-wikoqah8fura'", Local "Local file system at /tmp/rclone1597030733", Modify Window "1ms" --- PASS: TestMoveWithIgnoreExisting (4.62s) === RUN TestServerSideMove run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-wikoqah8fura'", Local "Local file system at /tmp/rclone1597030733", Modify Window "1ms" 2025/01/15 04:00:25 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-mesoyiv4wequ" 2025/01/15 04:00:25 DEBUG : Creating backend with remote "TestDrive:crypt/4s0kgbb7i9uoe8e6v1v5fgtn9fgj5389mcshshictc73bppkdi9g" 2025/01/15 04:00:27 DEBUG : potato2: md5 = d8863d21430694757c9a3b71edbde978 OK 2025/01/15 04:00:29 DEBUG : empty space: md5 = 8a971c27be9237498dcb3d1e19152dc5 OK 2025/01/15 04:00:31 DEBUG : potato3: md5 = 4cd15e395eaed588c4991d90b05fabf1 OK sync_test.go:1705: Server side move (if possible) Encrypted drive 'TestCryptDrive:rclone-test-wikoqah8fura' -> Encrypted drive 'TestCryptDrive:rclone-test-mesoyiv4wequ' 2025/01/15 04:00:34 DEBUG : empty space: md5 = 41225aee58285bf3bb2604224cde2797 OK 2025/01/15 04:00:35 DEBUG : potato3: md5 = 3fb9ac50cbb5bb2ca0e1863dd072ade9 OK 2025/01/15 04:00:36 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mesoyiv4wequ': Using server-side directory move 2025/01/15 04:00:36 INFO : Encrypted drive 'TestCryptDrive:rclone-test-mesoyiv4wequ': Server side directory move failed - fallback to file moves: can't copy directory - destination already exists 2025/01/15 04:00:36 DEBUG : potato2: Need to transfer - File not found at Destination 2025/01/15 04:00:36 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mesoyiv4wequ': Waiting for checks to finish 2025/01/15 04:00:36 DEBUG : potato3: Sizes differ (src 68 vs dst 60) 2025/01/15 04:00:36 DEBUG : empty space: Size and modification time the same (differ by 0s, within tolerance 1ms) 2025/01/15 04:00:36 DEBUG : empty space: Unchanged skipping 2025/01/15 04:00:36 INFO : empty space: Deleted 2025/01/15 04:00:36 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mesoyiv4wequ': Waiting for transfers to finish 2025/01/15 04:00:37 INFO : potato3: Deleted 2025/01/15 04:00:37 INFO : potato2: Moved (server-side) 2025/01/15 04:00:37 INFO : potato3: Moved (server-side) 2025/01/15 04:00:38 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-juraven6lowi" 2025/01/15 04:00:38 DEBUG : Creating backend with remote "TestDrive:crypt/4sa42018t4opcoas1au2oq17p0p649aeu4q6p62l92jlgclqbia0" 2025/01/15 04:00:39 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-juraven6lowi': Using server-side directory move 2025/01/15 04:00:40 INFO : Encrypted drive 'TestCryptDrive:rclone-test-juraven6lowi': Server side directory move succeeded 2025/01/15 04:00:41 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-juraven6lowi': Purge remote 2025/01/15 04:00:41 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-mesoyiv4wequ': Purge remote 2025/01/15 04:00:42 NOTICE: purge failed: directory not found --- PASS: TestServerSideMove (17.56s) === RUN TestServerSideMoveWithFilter run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-wikoqah8fura'", Local "Local file system at /tmp/rclone1597030733", Modify Window "1ms" 2025/01/15 04:00:42 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-vahiqek3sicu" 2025/01/15 04:00:42 DEBUG : Creating backend with remote "TestDrive:crypt/fv2bpue484b5mbkfkg8e4sg1egcrhndta5km6bltq2p28p7raagg" 2025/01/15 04:00:45 DEBUG : potato2: md5 = 8dfcad8be1925027c5ff1b487bf07abf OK 2025/01/15 04:00:47 DEBUG : empty space: md5 = 3ae5f32cc9d2d866d15125373e8412f8 OK 2025/01/15 04:00:48 DEBUG : potato3: md5 = 85bc852b4b9a96da048ddb72016be98e OK sync_test.go:1705: Server side move (if possible) Encrypted drive 'TestCryptDrive:rclone-test-wikoqah8fura' -> Encrypted drive 'TestCryptDrive:rclone-test-vahiqek3sicu' 2025/01/15 04:00:51 DEBUG : empty space: md5 = d2e2ee0b22f92572548c49de515e21b1 OK 2025/01/15 04:00:53 DEBUG : potato3: md5 = 454bbe5b1f867b6093a0255c91c64300 OK 2025/01/15 04:00:53 DEBUG : empty space: Excluded (Size Filter) 2025/01/15 04:00:53 DEBUG : empty space: Excluded (Size Filter) 2025/01/15 04:00:53 DEBUG : potato2: Need to transfer - File not found at Destination 2025/01/15 04:00:53 DEBUG : potato3: Sizes differ (src 68 vs dst 60) 2025/01/15 04:00:53 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vahiqek3sicu': Waiting for checks to finish 2025/01/15 04:00:53 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vahiqek3sicu': Waiting for transfers to finish 2025/01/15 04:00:54 INFO : potato3: Deleted 2025/01/15 04:00:55 INFO : potato2: Moved (server-side) 2025/01/15 04:00:55 INFO : potato3: Moved (server-side) 2025/01/15 04:00:56 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-qetejus1kuvo" 2025/01/15 04:00:56 DEBUG : Creating backend with remote "TestDrive:crypt/3llj3j88dgrj00kg92b254taghmnkq54fmcv95a5dtq9qjjrtq9g" 2025/01/15 04:00:57 DEBUG : empty space: Excluded (Size Filter) 2025/01/15 04:00:57 DEBUG : potato2: Need to transfer - File not found at Destination 2025/01/15 04:00:57 DEBUG : potato3: Need to transfer - File not found at Destination 2025/01/15 04:00:57 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-qetejus1kuvo': Waiting for checks to finish 2025/01/15 04:00:57 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-qetejus1kuvo': Waiting for transfers to finish 2025/01/15 04:00:59 INFO : potato3: Moved (server-side) 2025/01/15 04:00:59 INFO : potato2: Moved (server-side) 2025/01/15 04:01:00 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-qetejus1kuvo': Purge remote 2025/01/15 04:01:01 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vahiqek3sicu': Purge remote --- PASS: TestServerSideMoveWithFilter (20.87s) === RUN TestServerSideMoveDeleteEmptySourceDirs run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-wikoqah8fura'", Local "Local file system at /tmp/rclone1597030733", Modify Window "1ms" 2025/01/15 04:01:03 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-bayepay7funi" 2025/01/15 04:01:03 DEBUG : Creating backend with remote "TestDrive:crypt/j51sqgk0aanvldp0jbpa8kufidkk9huilga97d5isj7m0d6pu940" 2025/01/15 04:01:06 DEBUG : potato2: md5 = b4512084badfb0707b573fc4c9176ada OK 2025/01/15 04:01:07 DEBUG : empty space: md5 = 919067fbe4f26a6efc59d3ebfcddf381 OK 2025/01/15 04:01:09 DEBUG : potato3: md5 = dd0ff0e7ce9ca91fa35e5e323126243f OK 2025/01/15 04:01:09 INFO : tomatoDir: Making directory sync_test.go:1705: Server side move (if possible) Encrypted drive 'TestCryptDrive:rclone-test-wikoqah8fura' -> Encrypted drive 'TestCryptDrive:rclone-test-bayepay7funi' 2025/01/15 04:01:13 DEBUG : empty space: md5 = 6f35323eaa85f107a3524d9b2ea8c2f1 OK 2025/01/15 04:01:15 DEBUG : potato3: md5 = 8e7a31f5c49a17ac655362176ddf0066 OK 2025/01/15 04:01:15 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-bayepay7funi': Using server-side directory move 2025/01/15 04:01:15 INFO : Encrypted drive 'TestCryptDrive:rclone-test-bayepay7funi': Server side directory move failed - fallback to file moves: can't copy directory - destination already exists 2025/01/15 04:01:16 DEBUG : potato2: Need to transfer - File not found at Destination 2025/01/15 04:01:16 DEBUG : Added delayed dir = "tomatoDir", newDst= 2025/01/15 04:01:16 DEBUG : empty space: Size and modification time the same (differ by 0s, within tolerance 1ms) 2025/01/15 04:01:16 DEBUG : empty space: Unchanged skipping 2025/01/15 04:01:16 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-bayepay7funi': Waiting for checks to finish 2025/01/15 04:01:16 DEBUG : potato3: Sizes differ (src 68 vs dst 60) 2025/01/15 04:01:16 INFO : empty space: Deleted 2025/01/15 04:01:16 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-bayepay7funi': Waiting for transfers to finish 2025/01/15 04:01:16 INFO : potato3: Deleted 2025/01/15 04:01:17 INFO : potato2: Moved (server-side) 2025/01/15 04:01:17 INFO : potato3: Moved (server-side) 2025/01/15 04:01:17 INFO : tomatoDir: Removing directory 2025/01/15 04:01:18 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wikoqah8fura': deleted 1 directories 2025/01/15 04:01:19 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-fojugah1palo" 2025/01/15 04:01:19 DEBUG : Creating backend with remote "TestDrive:crypt/8e4aec7n075p8ed7hncrt5j6taqk54rkvqfua89vovr26527nku0" 2025/01/15 04:01:20 INFO : tomatoDir: Making directory 2025/01/15 04:01:21 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-fojugah1palo': Using server-side directory move 2025/01/15 04:01:22 INFO : Encrypted drive 'TestCryptDrive:rclone-test-fojugah1palo': Server side directory move succeeded 2025/01/15 04:01:24 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-fojugah1palo': Purge remote 2025/01/15 04:01:24 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-bayepay7funi': Purge remote 2025/01/15 04:01:24 NOTICE: purge failed: directory not found --- PASS: TestServerSideMoveDeleteEmptySourceDirs (21.88s) === RUN TestServerSideMoveOverlap run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-wikoqah8fura'", Local "Local file system at /tmp/rclone1597030733", Modify Window "1ms" sync_test.go:1910: Skipping test as remote supports DirMove --- SKIP: TestServerSideMoveOverlap (0.46s) === RUN TestSyncOverlap run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-wikoqah8fura'", Local "Local file system at /tmp/rclone1597030733", Modify Window "1ms" 2025/01/15 04:01:25 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-wikoqah8fura/rclone-sync-test" 2025/01/15 04:01:25 DEBUG : Creating backend with remote "TestDrive:crypt/p8337uk2j9qfur1l9kur6u0mduuvg126604snkhfdbjiae9gcnag/i7355aa0sb89uagn75vfjqr6s3e3e1h2et8in57abn1fe8qfego0" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-wikoqah8fura'", Local "Local file system at /tmp/rclone1597030733", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-wikoqah8fura'", Local "Local file system at /tmp/rclone1597030733", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-wikoqah8fura'", Local "Local file system at /tmp/rclone1597030733", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-wikoqah8fura'", Local "Local file system at /tmp/rclone1597030733", Modify Window "1ms" --- PASS: TestSyncOverlap (3.82s) === RUN TestSyncOverlapWithFilter run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-wikoqah8fura'", Local "Local file system at /tmp/rclone1597030733", Modify Window "1ms" 2025/01/15 04:01:29 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-wikoqah8fura/rclone-sync-test" 2025/01/15 04:01:29 DEBUG : Creating backend with remote "TestDrive:crypt/p8337uk2j9qfur1l9kur6u0mduuvg126604snkhfdbjiae9gcnag/i7355aa0sb89uagn75vfjqr6s3e3e1h2et8in57abn1fe8qfego0" 2025/01/15 04:01:32 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-wikoqah8fura/rclone-sync-test-include/layer2" 2025/01/15 04:01:32 DEBUG : Creating backend with remote "TestDrive:crypt/p8337uk2j9qfur1l9kur6u0mduuvg126604snkhfdbjiae9gcnag/khf2vlblvnbf9ftevqm0htmss73hj1j5a7q328e4ohrgs7e2loe0/n01jpl9202nn9ec1rb75h0f1c4" 2025/01/15 04:01:35 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-wikoqah8fura/rclone-sync-test-ignore-file" 2025/01/15 04:01:35 DEBUG : Creating backend with remote "TestDrive:crypt/p8337uk2j9qfur1l9kur6u0mduuvg126604snkhfdbjiae9gcnag/kmf11jujl9uha3tjganvgpkn45bu778hb5vb5riug1c26b38k7sg" 2025/01/15 04:01:39 DEBUG : rclone-sync-test-ignore-file/.ignore: md5 = 8754d0ee200f3e788442f6f2ce93877e OK 2025/01/15 04:01:41 DEBUG : Added delayed dir = "rclone-sync-test-include", newDst= 2025/01/15 04:01:41 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wikoqah8fura/rclone-sync-test': Waiting for checks to finish 2025/01/15 04:01:41 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wikoqah8fura/rclone-sync-test': Waiting for transfers to finish 2025/01/15 04:01:41 DEBUG : Waiting for deletions to finish 2025/01/15 04:01:41 INFO : There was nothing to transfer 2025/01/15 04:01:43 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wikoqah8fura': Waiting for checks to finish 2025/01/15 04:01:43 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wikoqah8fura': Waiting for transfers to finish 2025/01/15 04:01:43 DEBUG : Waiting for deletions to finish 2025/01/15 04:01:43 INFO : rclone-sync-test-include: Removing directory 2025/01/15 04:01:44 DEBUG : khf2vlblvnbf9ftevqm0htmss73hj1j5a7q328e4ohrgs7e2loe0: Rmdir: contains file: "n01jpl9202nn9ec1rb75h0f1c4" 2025/01/15 04:01:44 DEBUG : rclone-sync-test-include: Failed to Rmdir: directory not empty 2025/01/15 04:01:44 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wikoqah8fura': failed to delete 1 directories 2025/01/15 04:01:44 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-wikoqah8fura'", Local "Local file system at /tmp/rclone1597030733", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-wikoqah8fura'", Local "Local file system at /tmp/rclone1597030733", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-wikoqah8fura'", Local "Local file system at /tmp/rclone1597030733", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-wikoqah8fura'", Local "Local file system at /tmp/rclone1597030733", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-wikoqah8fura'", Local "Local file system at /tmp/rclone1597030733", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-wikoqah8fura'", Local "Local file system at /tmp/rclone1597030733", Modify Window "1ms" 2025/01/15 04:01:46 DEBUG : Added delayed dir = "rclone-sync-test-include", newDst= 2025/01/15 04:01:46 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wikoqah8fura/rclone-sync-test-include/layer2': Waiting for checks to finish 2025/01/15 04:01:46 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wikoqah8fura/rclone-sync-test-include/layer2': Waiting for transfers to finish 2025/01/15 04:01:46 DEBUG : Waiting for deletions to finish 2025/01/15 04:01:46 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-wikoqah8fura'", Local "Local file system at /tmp/rclone1597030733", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-wikoqah8fura'", Local "Local file system at /tmp/rclone1597030733", Modify Window "1ms" 2025/01/15 04:01:47 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wikoqah8fura': Waiting for checks to finish 2025/01/15 04:01:47 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wikoqah8fura': Waiting for transfers to finish 2025/01/15 04:01:47 DEBUG : Waiting for deletions to finish 2025/01/15 04:01:47 INFO : rclone-sync-test-include: Removing directory 2025/01/15 04:01:48 DEBUG : khf2vlblvnbf9ftevqm0htmss73hj1j5a7q328e4ohrgs7e2loe0: Rmdir: contains file: "n01jpl9202nn9ec1rb75h0f1c4" 2025/01/15 04:01:48 DEBUG : rclone-sync-test-include: Failed to Rmdir: directory not empty 2025/01/15 04:01:48 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wikoqah8fura': failed to delete 1 directories 2025/01/15 04:01:48 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-wikoqah8fura'", Local "Local file system at /tmp/rclone1597030733", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-wikoqah8fura'", Local "Local file system at /tmp/rclone1597030733", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-wikoqah8fura'", Local "Local file system at /tmp/rclone1597030733", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-wikoqah8fura'", Local "Local file system at /tmp/rclone1597030733", Modify Window "1ms" 2025/01/15 04:01:49 DEBUG : Added delayed dir = "rclone-sync-test-include", newDst= 2025/01/15 04:01:49 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wikoqah8fura/rclone-sync-test-ignore-file': Waiting for checks to finish 2025/01/15 04:01:49 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wikoqah8fura/rclone-sync-test-ignore-file': Waiting for transfers to finish 2025/01/15 04:01:49 DEBUG : Waiting for deletions to finish 2025/01/15 04:01:49 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-wikoqah8fura'", Local "Local file system at /tmp/rclone1597030733", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-wikoqah8fura'", Local "Local file system at /tmp/rclone1597030733", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-wikoqah8fura'", Local "Local file system at /tmp/rclone1597030733", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-wikoqah8fura'", Local "Local file system at /tmp/rclone1597030733", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-wikoqah8fura'", Local "Local file system at /tmp/rclone1597030733", Modify Window "1ms" 2025/01/15 04:01:52 DEBUG : khf2vlblvnbf9ftevqm0htmss73hj1j5a7q328e4ohrgs7e2loe0: Rmdir: contains trashed file: "n01jpl9202nn9ec1rb75h0f1c4" 2025/01/15 04:01:53 DEBUG : kmf11jujl9uha3tjganvgpkn45bu778hb5vb5riug1c26b38k7sg: Rmdir: contains trashed file: "i0t74httmdlljg425j6tg570d8" --- PASS: TestSyncOverlapWithFilter (33.32s) === RUN TestSyncCompareDest run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-wikoqah8fura'", Local "Local file system at /tmp/rclone1597030733", Modify Window "1ms" 2025/01/15 04:02:02 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-wikoqah8fura/dst" 2025/01/15 04:02:02 DEBUG : Creating backend with remote "TestDrive:crypt/p8337uk2j9qfur1l9kur6u0mduuvg126604snkhfdbjiae9gcnag/31u3jie661vd5p8j7rtc3hgbh0" 2025/01/15 04:02:04 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-wikoqah8fura/CompareDest" 2025/01/15 04:02:04 DEBUG : Creating backend with remote "TestDrive:crypt/p8337uk2j9qfur1l9kur6u0mduuvg126604snkhfdbjiae9gcnag/gveqi14airsml4bgu7krj116o8" 2025/01/15 04:02:06 DEBUG : one: Need to transfer - File not found at Destination 2025/01/15 04:02:06 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wikoqah8fura/dst': Waiting for checks to finish 2025/01/15 04:02:06 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wikoqah8fura/dst': Waiting for transfers to finish 2025/01/15 04:02:09 DEBUG : one: md5 = 6a30c4e614259f181bee8b2e36bb23aa OK 2025/01/15 04:02:09 INFO : one: Copied (new) 2025/01/15 04:02:09 DEBUG : Waiting for deletions to finish 2025/01/15 04:02:10 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wikoqah8fura/dst': Waiting for checks to finish 2025/01/15 04:02:10 DEBUG : one: Sizes differ (src 5 vs dst 3) 2025/01/15 04:02:10 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wikoqah8fura/dst': Waiting for transfers to finish 2025/01/15 04:02:12 DEBUG : one: md5 = bb5558142da9aec777f631a476fe5e36 OK 2025/01/15 04:02:12 INFO : one: Copied (replaced existing) 2025/01/15 04:02:12 DEBUG : Waiting for deletions to finish 2025/01/15 04:02:14 DEBUG : dst/one: md5 = bac0fd328abd155c75898ee5bda87ec9 OK 2025/01/15 04:02:16 DEBUG : CompareDest/one: md5 = 2f98d774c0ea3d5badbd542001e4f4d1 OK 2025/01/15 04:02:17 DEBUG : one: Sizes differ (src 5 vs dst 3) 2025/01/15 04:02:17 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wikoqah8fura/dst': Waiting for checks to finish 2025/01/15 04:02:17 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/01/15 04:02:17 DEBUG : one: Destination found in --compare-dest, skipping 2025/01/15 04:02:17 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wikoqah8fura/dst': Waiting for transfers to finish 2025/01/15 04:02:17 DEBUG : Waiting for deletions to finish 2025/01/15 04:02:17 INFO : There was nothing to transfer 2025/01/15 04:02:19 DEBUG : CompareDest/two: md5 = 3bd5c0cf3d1c4bf438511d4442bb0b34 OK 2025/01/15 04:02:20 DEBUG : two: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/01/15 04:02:20 DEBUG : two: Destination found in --compare-dest, skipping 2025/01/15 04:02:20 DEBUG : one: Sizes differ (src 5 vs dst 3) 2025/01/15 04:02:20 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wikoqah8fura/dst': Waiting for checks to finish 2025/01/15 04:02:21 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/01/15 04:02:21 DEBUG : one: Destination found in --compare-dest, skipping 2025/01/15 04:02:21 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wikoqah8fura/dst': Waiting for transfers to finish 2025/01/15 04:02:21 DEBUG : Waiting for deletions to finish 2025/01/15 04:02:21 INFO : There was nothing to transfer 2025/01/15 04:02:22 DEBUG : two: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/01/15 04:02:22 DEBUG : two: Destination found in --compare-dest, skipping 2025/01/15 04:02:22 DEBUG : one: Sizes differ (src 5 vs dst 3) 2025/01/15 04:02:22 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wikoqah8fura/dst': Waiting for checks to finish 2025/01/15 04:02:22 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/01/15 04:02:22 DEBUG : one: Destination found in --compare-dest, skipping 2025/01/15 04:02:22 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wikoqah8fura/dst': Waiting for transfers to finish 2025/01/15 04:02:22 DEBUG : Waiting for deletions to finish 2025/01/15 04:02:22 INFO : There was nothing to transfer sync_test.go:2175: No hash on uploaded file so skipping compare timestamp test 2025/01/15 04:02:23 DEBUG : two: Sizes differ (src 5 vs dst 3) 2025/01/15 04:02:23 DEBUG : two: Need to transfer - File not found at Destination 2025/01/15 04:02:23 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wikoqah8fura/dst': Waiting for checks to finish 2025/01/15 04:02:23 DEBUG : one: Sizes differ (src 5 vs dst 3) 2025/01/15 04:02:24 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/01/15 04:02:24 DEBUG : one: Destination found in --compare-dest, skipping 2025/01/15 04:02:24 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wikoqah8fura/dst': Waiting for transfers to finish 2025/01/15 04:02:25 DEBUG : two: md5 = 50b618ab8d6e1efde7d9d29db5379907 OK 2025/01/15 04:02:25 INFO : two: Copied (new) 2025/01/15 04:02:25 DEBUG : Waiting for deletions to finish 2025/01/15 04:02:29 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k" 2025/01/15 04:02:29 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" 2025/01/15 04:02:30 DEBUG : gveqi14airsml4bgu7krj116o8: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k" 2025/01/15 04:02:30 DEBUG : gveqi14airsml4bgu7krj116o8: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" --- PASS: TestSyncCompareDest (28.24s) === RUN TestSyncMultipleCompareDest run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-wikoqah8fura'", Local "Local file system at /tmp/rclone1597030733", Modify Window "1ms" 2025/01/15 04:02:34 DEBUG : pre-dest1/1: md5 = 9a87a1ffb89e7c49dc64797573a9d1d6 OK 2025/01/15 04:02:36 DEBUG : pre-dest2/2: md5 = 8ab85b7e6a099188e5d2f374bf282ce1 OK 2025/01/15 04:02:36 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-wikoqah8fura/dest" 2025/01/15 04:02:37 DEBUG : Creating backend with remote "TestDrive:crypt/p8337uk2j9qfur1l9kur6u0mduuvg126604snkhfdbjiae9gcnag/rg03c1jvnehrrc617i0lnqjddc" 2025/01/15 04:02:38 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-wikoqah8fura/pre-dest1" 2025/01/15 04:02:38 DEBUG : Creating backend with remote "TestDrive:crypt/p8337uk2j9qfur1l9kur6u0mduuvg126604snkhfdbjiae9gcnag/bbnblvh6k061ssopqrp18kd7gc" 2025/01/15 04:02:39 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-wikoqah8fura/pre-dest2" 2025/01/15 04:02:39 DEBUG : Creating backend with remote "TestDrive:crypt/p8337uk2j9qfur1l9kur6u0mduuvg126604snkhfdbjiae9gcnag/dgicm1h6b5ejvlltm8eeif0bnk" 2025/01/15 04:02:40 DEBUG : 1: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/01/15 04:02:40 DEBUG : 1: Destination found in --compare-dest, skipping 2025/01/15 04:02:41 DEBUG : 2: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/01/15 04:02:41 DEBUG : 2: Destination found in --compare-dest, skipping 2025/01/15 04:02:41 DEBUG : 3: Need to transfer - File not found at Destination 2025/01/15 04:02:41 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wikoqah8fura/dest': Waiting for checks to finish 2025/01/15 04:02:41 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wikoqah8fura/dest': Waiting for transfers to finish 2025/01/15 04:02:44 DEBUG : 3: md5 = 66759214ff7bae8970bfbf6887765b67 OK 2025/01/15 04:02:44 INFO : 3: Copied (new) 2025/01/15 04:02:44 DEBUG : Waiting for deletions to finish 2025/01/15 04:02:47 DEBUG : dgicm1h6b5ejvlltm8eeif0bnk: Rmdir: contains trashed file: "1ghu8geql9vrl726n32nrf65bc" 2025/01/15 04:02:48 DEBUG : bbnblvh6k061ssopqrp18kd7gc: Rmdir: contains trashed file: "skbfko3oil7es0lj68ob574sro" 2025/01/15 04:02:49 DEBUG : rg03c1jvnehrrc617i0lnqjddc: Rmdir: contains trashed file: "g072p7hmjchlnj0gibe64c1epg" --- PASS: TestSyncMultipleCompareDest (18.63s) === RUN TestSyncCopyDest run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-wikoqah8fura'", Local "Local file system at /tmp/rclone1597030733", Modify Window "1ms" 2025/01/15 04:02:49 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-wikoqah8fura/dst" 2025/01/15 04:02:49 DEBUG : Creating backend with remote "TestDrive:crypt/p8337uk2j9qfur1l9kur6u0mduuvg126604snkhfdbjiae9gcnag/31u3jie661vd5p8j7rtc3hgbh0" 2025/01/15 04:02:51 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-wikoqah8fura/CopyDest" 2025/01/15 04:02:51 DEBUG : Creating backend with remote "TestDrive:crypt/p8337uk2j9qfur1l9kur6u0mduuvg126604snkhfdbjiae9gcnag/d09o6po3f7bm6ce32vdgs8h9ls" 2025/01/15 04:02:53 DEBUG : one: Need to transfer - File not found at Destination 2025/01/15 04:02:53 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wikoqah8fura/dst': Waiting for checks to finish 2025/01/15 04:02:53 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wikoqah8fura/dst': Waiting for transfers to finish 2025/01/15 04:02:56 DEBUG : one: md5 = c1abd6e79abb6734f41740a2fd10f4e5 OK 2025/01/15 04:02:56 INFO : one: Copied (new) 2025/01/15 04:02:56 DEBUG : Waiting for deletions to finish 2025/01/15 04:02:57 DEBUG : one: Sizes differ (src 5 vs dst 3) 2025/01/15 04:02:57 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wikoqah8fura/dst': Waiting for checks to finish 2025/01/15 04:02:57 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wikoqah8fura/dst': Waiting for transfers to finish 2025/01/15 04:02:59 DEBUG : one: md5 = c2c146e1806c371c36767d3d8f67e562 OK 2025/01/15 04:02:59 INFO : one: Copied (replaced existing) 2025/01/15 04:02:59 DEBUG : Waiting for deletions to finish 2025/01/15 04:03:01 DEBUG : dst/one: md5 = 39579fc8d8551d616e2a4ee30aad856d OK 2025/01/15 04:03:03 DEBUG : CopyDest/one: md5 = b9fee74451ca41695bdf5edfd00cb66e OK 2025/01/15 04:03:04 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-wikoqah8fura/BackupDir" 2025/01/15 04:03:04 DEBUG : Creating backend with remote "TestDrive:crypt/p8337uk2j9qfur1l9kur6u0mduuvg126604snkhfdbjiae9gcnag/s6dbk3lfi7c9kfvo6j7bla9m0g" 2025/01/15 04:03:06 DEBUG : one: Sizes differ (src 5 vs dst 3) 2025/01/15 04:03:06 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wikoqah8fura/dst': Waiting for checks to finish 2025/01/15 04:03:06 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/01/15 04:03:06 DEBUG : one: Sizes differ (src 5 vs dst 3) 2025/01/15 04:03:08 INFO : one: Moved (server-side) 2025/01/15 04:03:10 INFO : one: Copied (server-side copy) 2025/01/15 04:03:10 DEBUG : one: Destination found in --copy-dest, using server-side copy 2025/01/15 04:03:10 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wikoqah8fura/dst': Waiting for transfers to finish 2025/01/15 04:03:10 DEBUG : Waiting for deletions to finish 2025/01/15 04:03:12 DEBUG : CopyDest/two: md5 = 8a2d9a141caa6cd3366a10a9ac262c26 OK 2025/01/15 04:03:13 DEBUG : two: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/01/15 04:03:14 INFO : two: Copied (server-side copy) 2025/01/15 04:03:14 DEBUG : two: Destination found in --copy-dest, using server-side copy 2025/01/15 04:03:14 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/01/15 04:03:14 DEBUG : one: Unchanged skipping 2025/01/15 04:03:14 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wikoqah8fura/dst': Waiting for checks to finish 2025/01/15 04:03:14 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wikoqah8fura/dst': Waiting for transfers to finish 2025/01/15 04:03:14 DEBUG : Waiting for deletions to finish 2025/01/15 04:03:15 DEBUG : two: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/01/15 04:03:15 DEBUG : two: Unchanged skipping 2025/01/15 04:03:15 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/01/15 04:03:15 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wikoqah8fura/dst': Waiting for checks to finish 2025/01/15 04:03:15 DEBUG : one: Unchanged skipping 2025/01/15 04:03:15 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wikoqah8fura/dst': Waiting for transfers to finish 2025/01/15 04:03:15 DEBUG : Waiting for deletions to finish 2025/01/15 04:03:15 INFO : There was nothing to transfer 2025/01/15 04:03:17 DEBUG : CopyDest/three: md5 = c914ef25ac5d49cd2c941c48c343fc20 OK 2025/01/15 04:03:18 DEBUG : three: Sizes differ (src 7 vs dst 5) 2025/01/15 04:03:18 DEBUG : three: Destination not found in --copy-dest 2025/01/15 04:03:18 DEBUG : three: Need to transfer - File not found at Destination 2025/01/15 04:03:18 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/01/15 04:03:18 DEBUG : one: Unchanged skipping 2025/01/15 04:03:18 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wikoqah8fura/dst': Waiting for checks to finish 2025/01/15 04:03:18 DEBUG : two: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/01/15 04:03:18 DEBUG : two: Unchanged skipping 2025/01/15 04:03:18 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wikoqah8fura/dst': Waiting for transfers to finish 2025/01/15 04:03:20 DEBUG : three: md5 = 5d496d97f9b17be7147b51ef31cf920b OK 2025/01/15 04:03:20 INFO : three: Copied (new) 2025/01/15 04:03:20 DEBUG : Waiting for deletions to finish 2025/01/15 04:03:26 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "b6jdmn2b1adrhc8vikh7edr9os" 2025/01/15 04:03:26 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k" 2025/01/15 04:03:26 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" 2025/01/15 04:03:27 DEBUG : d09o6po3f7bm6ce32vdgs8h9ls: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k" 2025/01/15 04:03:27 DEBUG : d09o6po3f7bm6ce32vdgs8h9ls: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" 2025/01/15 04:03:27 DEBUG : d09o6po3f7bm6ce32vdgs8h9ls: Rmdir: contains trashed file: "b6jdmn2b1adrhc8vikh7edr9os" 2025/01/15 04:03:27 DEBUG : s6dbk3lfi7c9kfvo6j7bla9m0g: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" --- PASS: TestSyncCopyDest (38.86s) === RUN TestSyncBackupDir run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-wikoqah8fura'", Local "Local file system at /tmp/rclone1597030733", Modify Window "1ms" 2025/01/15 04:03:31 DEBUG : dst/one: md5 = b1761ef704d7be77c5be1ce9b4da104a OK 2025/01/15 04:03:33 DEBUG : dst/two: md5 = 8e9cbb9ab56a94d8e5152f833af6c6c2 OK 2025/01/15 04:03:34 DEBUG : dst/three.txt: md5 = b152bece8182a903d9bcbed353b51eb2 OK 2025/01/15 04:03:35 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-wikoqah8fura/dst" 2025/01/15 04:03:35 DEBUG : Creating backend with remote "TestDrive:crypt/p8337uk2j9qfur1l9kur6u0mduuvg126604snkhfdbjiae9gcnag/31u3jie661vd5p8j7rtc3hgbh0" 2025/01/15 04:03:35 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-wikoqah8fura/backup" 2025/01/15 04:03:35 DEBUG : Creating backend with remote "TestDrive:crypt/p8337uk2j9qfur1l9kur6u0mduuvg126604snkhfdbjiae9gcnag/1nrff024r7pq65ecp72fc28jb0" 2025/01/15 04:03:37 DEBUG : one: Sizes differ (src 4 vs dst 3) 2025/01/15 04:03:37 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/01/15 04:03:37 DEBUG : two: Unchanged skipping 2025/01/15 04:03:37 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wikoqah8fura/dst': Waiting for checks to finish 2025/01/15 04:03:39 INFO : one: Moved (server-side) 2025/01/15 04:03:39 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wikoqah8fura/dst': Waiting for transfers to finish 2025/01/15 04:03:41 DEBUG : one: md5 = a54cccbd5784acf938d1a24b12a3e715 OK 2025/01/15 04:03:41 INFO : one: Copied (new) 2025/01/15 04:03:41 DEBUG : Waiting for deletions to finish 2025/01/15 04:03:42 INFO : three.txt: Moved (server-side) 2025/01/15 04:03:42 INFO : three.txt: Moved into backup dir 2025/01/15 04:03:44 DEBUG : dst/three.txt: md5 = c9564bdb0646eb430331d9bdf19e37e2 OK 2025/01/15 04:03:45 DEBUG : one: Sizes differ (src 5 vs dst 4) 2025/01/15 04:03:45 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/01/15 04:03:45 DEBUG : two: Unchanged skipping 2025/01/15 04:03:45 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wikoqah8fura/dst': Waiting for checks to finish 2025/01/15 04:03:46 INFO : one: Deleted 2025/01/15 04:03:47 INFO : one: Moved (server-side) 2025/01/15 04:03:47 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wikoqah8fura/dst': Waiting for transfers to finish 2025/01/15 04:03:49 DEBUG : one: md5 = d35fc73b007aced0a3de3168c4d06f29 OK 2025/01/15 04:03:49 INFO : one: Copied (new) 2025/01/15 04:03:49 DEBUG : Waiting for deletions to finish 2025/01/15 04:03:50 INFO : three.txt: Deleted 2025/01/15 04:03:51 INFO : three.txt: Moved (server-side) 2025/01/15 04:03:51 INFO : three.txt: Moved into backup dir 2025/01/15 04:03:54 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" 2025/01/15 04:03:54 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k" 2025/01/15 04:03:55 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" 2025/01/15 04:03:55 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "tr2hj63d80ftlmvm6a952snjcc" 2025/01/15 04:03:55 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "tr2hj63d80ftlmvm6a952snjcc" 2025/01/15 04:03:55 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" --- PASS: TestSyncBackupDir (27.90s) === RUN TestSyncBackupDirWithSuffix run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-wikoqah8fura'", Local "Local file system at /tmp/rclone1597030733", Modify Window "1ms" 2025/01/15 04:03:59 DEBUG : dst/one: md5 = fc8c283a6fa010fe59e3cfe2dbf00b55 OK 2025/01/15 04:04:01 DEBUG : dst/two: md5 = 273ad35ed376bcfe8cb11ec05d5fb0ae OK 2025/01/15 04:04:02 DEBUG : dst/three.txt: md5 = c1558ba6f456d6cadb58d3d29560f228 OK 2025/01/15 04:04:03 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-wikoqah8fura/dst" 2025/01/15 04:04:03 DEBUG : Creating backend with remote "TestDrive:crypt/p8337uk2j9qfur1l9kur6u0mduuvg126604snkhfdbjiae9gcnag/31u3jie661vd5p8j7rtc3hgbh0" 2025/01/15 04:04:04 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-wikoqah8fura/backup" 2025/01/15 04:04:04 DEBUG : Creating backend with remote "TestDrive:crypt/p8337uk2j9qfur1l9kur6u0mduuvg126604snkhfdbjiae9gcnag/1nrff024r7pq65ecp72fc28jb0" 2025/01/15 04:04:06 DEBUG : one: Sizes differ (src 4 vs dst 3) 2025/01/15 04:04:06 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/01/15 04:04:06 DEBUG : two: Unchanged skipping 2025/01/15 04:04:06 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wikoqah8fura/dst': Waiting for checks to finish 2025/01/15 04:04:08 INFO : one: Moved (server-side) to: one.bak 2025/01/15 04:04:08 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wikoqah8fura/dst': Waiting for transfers to finish 2025/01/15 04:04:09 DEBUG : one: md5 = 7154c0c26683fedc4598ad74c0ffc0b9 OK 2025/01/15 04:04:09 INFO : one: Copied (new) 2025/01/15 04:04:09 DEBUG : Waiting for deletions to finish 2025/01/15 04:04:11 INFO : three.txt: Moved (server-side) to: three.txt.bak 2025/01/15 04:04:11 INFO : three.txt: Moved into backup dir 2025/01/15 04:04:13 DEBUG : dst/three.txt: md5 = f2fde8dfb4556a577e1e661543a05550 OK 2025/01/15 04:04:13 DEBUG : one: Sizes differ (src 5 vs dst 4) 2025/01/15 04:04:13 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wikoqah8fura/dst': Waiting for checks to finish 2025/01/15 04:04:13 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/01/15 04:04:13 DEBUG : two: Unchanged skipping 2025/01/15 04:04:14 INFO : one.bak: Deleted 2025/01/15 04:04:15 INFO : one: Moved (server-side) to: one.bak 2025/01/15 04:04:15 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wikoqah8fura/dst': Waiting for transfers to finish 2025/01/15 04:04:17 DEBUG : one: md5 = 1214e6975d90c5bcd57392553165f3c3 OK 2025/01/15 04:04:17 INFO : one: Copied (new) 2025/01/15 04:04:17 DEBUG : Waiting for deletions to finish 2025/01/15 04:04:18 INFO : three.txt.bak: Deleted 2025/01/15 04:04:19 INFO : three.txt: Moved (server-side) to: three.txt.bak 2025/01/15 04:04:19 INFO : three.txt: Moved into backup dir 2025/01/15 04:04:23 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" 2025/01/15 04:04:23 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k" 2025/01/15 04:04:23 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "sk91qgsqfn0r271r2ehsaoc20c" 2025/01/15 04:04:23 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "qltcak2uaegtmcoa8vijdppbp8" 2025/01/15 04:04:23 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "qltcak2uaegtmcoa8vijdppbp8" 2025/01/15 04:04:23 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "sk91qgsqfn0r271r2ehsaoc20c" --- PASS: TestSyncBackupDirWithSuffix (28.28s) === RUN TestSyncBackupDirWithSuffixKeepExtension run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-wikoqah8fura'", Local "Local file system at /tmp/rclone1597030733", Modify Window "1ms" 2025/01/15 04:04:27 DEBUG : dst/one: md5 = 5a03313974bb5a3447e096b47c3a54ac OK 2025/01/15 04:04:29 DEBUG : dst/two: md5 = f7f3e2821ffa22049ac167e1de546b98 OK 2025/01/15 04:04:30 DEBUG : dst/three.txt: md5 = ec9b6dd51532468f2186121ef449d35c OK 2025/01/15 04:04:31 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-wikoqah8fura/dst" 2025/01/15 04:04:31 DEBUG : Creating backend with remote "TestDrive:crypt/p8337uk2j9qfur1l9kur6u0mduuvg126604snkhfdbjiae9gcnag/31u3jie661vd5p8j7rtc3hgbh0" 2025/01/15 04:04:31 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-wikoqah8fura/backup" 2025/01/15 04:04:31 DEBUG : Creating backend with remote "TestDrive:crypt/p8337uk2j9qfur1l9kur6u0mduuvg126604snkhfdbjiae9gcnag/1nrff024r7pq65ecp72fc28jb0" 2025/01/15 04:04:33 DEBUG : one: Sizes differ (src 4 vs dst 3) 2025/01/15 04:04:33 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/01/15 04:04:33 DEBUG : two: Unchanged skipping 2025/01/15 04:04:33 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wikoqah8fura/dst': Waiting for checks to finish 2025/01/15 04:04:35 INFO : one: Moved (server-side) to: one-2019-01-01 2025/01/15 04:04:35 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wikoqah8fura/dst': Waiting for transfers to finish 2025/01/15 04:04:37 DEBUG : one: md5 = 83e529d0aeb62d7a4fd854484bb0d572 OK 2025/01/15 04:04:37 INFO : one: Copied (new) 2025/01/15 04:04:37 DEBUG : Waiting for deletions to finish 2025/01/15 04:04:38 INFO : three.txt: Moved (server-side) to: three-2019-01-01.txt 2025/01/15 04:04:38 INFO : three.txt: Moved into backup dir 2025/01/15 04:04:41 DEBUG : dst/three.txt: md5 = 4fc3bc14e61f0f5c3fbadbe2a9384557 OK 2025/01/15 04:04:42 DEBUG : one: Sizes differ (src 5 vs dst 4) 2025/01/15 04:04:42 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/01/15 04:04:42 DEBUG : two: Unchanged skipping 2025/01/15 04:04:42 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wikoqah8fura/dst': Waiting for checks to finish 2025/01/15 04:04:42 INFO : one-2019-01-01: Deleted 2025/01/15 04:04:43 INFO : one: Moved (server-side) to: one-2019-01-01 2025/01/15 04:04:43 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wikoqah8fura/dst': Waiting for transfers to finish 2025/01/15 04:04:45 DEBUG : one: md5 = 7782e29642f9b8791c5338419df78b34 OK 2025/01/15 04:04:45 INFO : one: Copied (new) 2025/01/15 04:04:45 DEBUG : Waiting for deletions to finish 2025/01/15 04:04:46 INFO : three-2019-01-01.txt: Deleted 2025/01/15 04:04:47 INFO : three.txt: Moved (server-side) to: three-2019-01-01.txt 2025/01/15 04:04:47 INFO : three.txt: Moved into backup dir 2025/01/15 04:04:51 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" 2025/01/15 04:04:51 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k" 2025/01/15 04:04:51 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "qtq2f6qq4lgpsmj88vb7147qje3prudmtfdtr2342fth58vo9a50" 2025/01/15 04:04:51 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "jcjl1bv3ep0v8kt35lqql1co90" 2025/01/15 04:04:51 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "jcjl1bv3ep0v8kt35lqql1co90" 2025/01/15 04:04:51 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "qtq2f6qq4lgpsmj88vb7147qje3prudmtfdtr2342fth58vo9a50" --- PASS: TestSyncBackupDirWithSuffixKeepExtension (27.91s) === RUN TestSyncBackupDirSuffixOnly run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-wikoqah8fura'", Local "Local file system at /tmp/rclone1597030733", Modify Window "1ms" 2025/01/15 04:04:55 DEBUG : dst/one: md5 = f5d9037ad2602602f7466fe6556ebce4 OK 2025/01/15 04:04:57 DEBUG : dst/two: md5 = 5e77a30078d3012ed8809fbd3c34931c OK 2025/01/15 04:04:58 DEBUG : dst/three.txt: md5 = 058abd158d58538f5b76c552e45b46a3 OK 2025/01/15 04:04:59 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-wikoqah8fura/dst" 2025/01/15 04:04:59 DEBUG : Creating backend with remote "TestDrive:crypt/p8337uk2j9qfur1l9kur6u0mduuvg126604snkhfdbjiae9gcnag/31u3jie661vd5p8j7rtc3hgbh0" 2025/01/15 04:05:00 DEBUG : one: Sizes differ (src 4 vs dst 3) 2025/01/15 04:05:00 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/01/15 04:05:00 DEBUG : two: Unchanged skipping 2025/01/15 04:05:00 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wikoqah8fura/dst': Waiting for checks to finish 2025/01/15 04:05:01 INFO : one: Moved (server-side) to: one.bak 2025/01/15 04:05:01 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wikoqah8fura/dst': Waiting for transfers to finish 2025/01/15 04:05:02 DEBUG : one: md5 = 5bee0e0291d07504964eb14deeb7a77f OK 2025/01/15 04:05:02 INFO : one: Copied (new) 2025/01/15 04:05:02 DEBUG : Waiting for deletions to finish 2025/01/15 04:05:03 INFO : three.txt: Moved (server-side) to: three.txt.bak 2025/01/15 04:05:03 INFO : three.txt: Moved into backup dir 2025/01/15 04:05:05 DEBUG : dst/three.txt: md5 = 9da6c95d9647d3276764dba1784c33a8 OK 2025/01/15 04:05:06 DEBUG : three.txt.bak: Excluded (Path Filter) 2025/01/15 04:05:06 DEBUG : one.bak: Excluded (Path Filter) 2025/01/15 04:05:06 DEBUG : one: Sizes differ (src 5 vs dst 4) 2025/01/15 04:05:06 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/01/15 04:05:06 DEBUG : two: Unchanged skipping 2025/01/15 04:05:06 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wikoqah8fura/dst': Waiting for checks to finish 2025/01/15 04:05:07 INFO : one.bak: Deleted 2025/01/15 04:05:07 INFO : one: Moved (server-side) to: one.bak 2025/01/15 04:05:07 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wikoqah8fura/dst': Waiting for transfers to finish 2025/01/15 04:05:09 DEBUG : one: md5 = c993ccbc354c52c771ebc27a8924df4f OK 2025/01/15 04:05:09 INFO : one: Copied (new) 2025/01/15 04:05:09 DEBUG : Waiting for deletions to finish 2025/01/15 04:05:10 INFO : three.txt.bak: Deleted 2025/01/15 04:05:10 INFO : three.txt: Moved (server-side) to: three.txt.bak 2025/01/15 04:05:10 INFO : three.txt: Moved into backup dir 2025/01/15 04:05:14 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" 2025/01/15 04:05:14 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "qltcak2uaegtmcoa8vijdppbp8" 2025/01/15 04:05:14 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "sk91qgsqfn0r271r2ehsaoc20c" 2025/01/15 04:05:14 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "sk91qgsqfn0r271r2ehsaoc20c" 2025/01/15 04:05:14 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "qltcak2uaegtmcoa8vijdppbp8" 2025/01/15 04:05:14 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k" --- PASS: TestSyncBackupDirSuffixOnly (22.70s) === RUN TestSyncSuffix run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-wikoqah8fura'", Local "Local file system at /tmp/rclone1597030733", Modify Window "1ms" 2025/01/15 04:05:18 DEBUG : dst/one: md5 = df5ff43016584c9bf5b46f2b75e4e87e OK 2025/01/15 04:05:19 DEBUG : dst/two: md5 = b36970335f4055815dac5ef6b5bfe583 OK 2025/01/15 04:05:21 DEBUG : dst/three.txt: md5 = 90de57dddeb831787790c94770a83c55 OK 2025/01/15 04:05:21 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-wikoqah8fura/dst" 2025/01/15 04:05:21 DEBUG : Creating backend with remote "TestDrive:crypt/p8337uk2j9qfur1l9kur6u0mduuvg126604snkhfdbjiae9gcnag/31u3jie661vd5p8j7rtc3hgbh0" 2025/01/15 04:05:22 DEBUG : one: Sizes differ (src 4 vs dst 3) 2025/01/15 04:05:23 INFO : one: Moved (server-side) to: one.bak 2025/01/15 04:05:25 DEBUG : one: md5 = a2b6f27e72806720d9d888989707993a OK 2025/01/15 04:05:25 INFO : one: Copied (new) 2025/01/15 04:05:26 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/01/15 04:05:26 DEBUG : two: Unchanged skipping 2025/01/15 04:05:26 DEBUG : three.txt: Sizes differ (src 6 vs dst 5) 2025/01/15 04:05:27 INFO : three.txt: Moved (server-side) to: three.txt.bak 2025/01/15 04:05:29 DEBUG : three.txt: md5 = 4b575ead766ade0ffb2477f0da5595ef OK 2025/01/15 04:05:29 INFO : three.txt: Copied (new) 2025/01/15 04:05:30 DEBUG : one: Sizes differ (src 5 vs dst 4) 2025/01/15 04:05:31 INFO : one.bak: Deleted 2025/01/15 04:05:31 INFO : one: Moved (server-side) to: one.bak 2025/01/15 04:05:33 DEBUG : one: md5 = 87fd6f4f1f3dfcaf0378d37aa0a84cad OK 2025/01/15 04:05:33 INFO : one: Copied (new) 2025/01/15 04:05:33 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/01/15 04:05:33 DEBUG : two: Unchanged skipping 2025/01/15 04:05:34 DEBUG : three.txt: Sizes differ (src 19 vs dst 6) 2025/01/15 04:05:34 INFO : three.txt.bak: Deleted 2025/01/15 04:05:35 INFO : three.txt: Moved (server-side) to: three.txt.bak 2025/01/15 04:05:37 DEBUG : three.txt: md5 = 2110fb871efe3a231d3380eb9374795a OK 2025/01/15 04:05:37 INFO : three.txt: Copied (new) 2025/01/15 04:05:41 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" 2025/01/15 04:05:41 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "tr2hj63d80ftlmvm6a952snjcc" 2025/01/15 04:05:41 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "qltcak2uaegtmcoa8vijdppbp8" 2025/01/15 04:05:41 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "qltcak2uaegtmcoa8vijdppbp8" 2025/01/15 04:05:41 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "sk91qgsqfn0r271r2ehsaoc20c" 2025/01/15 04:05:41 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k" 2025/01/15 04:05:41 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "sk91qgsqfn0r271r2ehsaoc20c" --- PASS: TestSyncSuffix (27.24s) === RUN TestSyncSuffixKeepExtension run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-wikoqah8fura'", Local "Local file system at /tmp/rclone1597030733", Modify Window "1ms" 2025/01/15 04:05:45 DEBUG : dst/one: md5 = 4354297cf0dfed514eb2df6ddedc603b OK 2025/01/15 04:05:46 DEBUG : dst/two: md5 = 8cad82436279108805f0b9caa101886a OK 2025/01/15 04:05:48 DEBUG : dst/three.txt: md5 = a02345ad84cabf98605a94983389ef3b OK 2025/01/15 04:05:49 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-wikoqah8fura/dst" 2025/01/15 04:05:49 DEBUG : Creating backend with remote "TestDrive:crypt/p8337uk2j9qfur1l9kur6u0mduuvg126604snkhfdbjiae9gcnag/31u3jie661vd5p8j7rtc3hgbh0" 2025/01/15 04:05:50 DEBUG : one: Sizes differ (src 4 vs dst 3) 2025/01/15 04:05:51 INFO : one: Moved (server-side) to: one-2019-01-01 2025/01/15 04:05:52 DEBUG : one: md5 = 47753dec8e1c778f4d9902ade7cb8fae OK 2025/01/15 04:05:52 INFO : one: Copied (new) 2025/01/15 04:05:53 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/01/15 04:05:53 DEBUG : two: Unchanged skipping 2025/01/15 04:05:53 DEBUG : three.txt: Sizes differ (src 6 vs dst 5) 2025/01/15 04:05:54 INFO : three.txt: Moved (server-side) to: three-2019-01-01.txt 2025/01/15 04:05:55 DEBUG : three.txt: md5 = 00155d9c9dad492daefa6c992a0bb7de OK 2025/01/15 04:05:55 INFO : three.txt: Copied (new) 2025/01/15 04:05:57 DEBUG : one: Sizes differ (src 5 vs dst 4) 2025/01/15 04:05:58 INFO : one-2019-01-01: Deleted 2025/01/15 04:05:58 INFO : one: Moved (server-side) to: one-2019-01-01 2025/01/15 04:06:00 DEBUG : one: md5 = 6f2473828075c80cfd941761bd697e55 OK 2025/01/15 04:06:00 INFO : one: Copied (new) 2025/01/15 04:06:00 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/01/15 04:06:00 DEBUG : two: Unchanged skipping 2025/01/15 04:06:00 DEBUG : three.txt: Sizes differ (src 19 vs dst 6) 2025/01/15 04:06:01 INFO : three-2019-01-01.txt: Deleted 2025/01/15 04:06:02 INFO : three.txt: Moved (server-side) to: three-2019-01-01.txt 2025/01/15 04:06:04 DEBUG : three.txt: md5 = f6048daf824c1f89646674529235a36f OK 2025/01/15 04:06:04 INFO : three.txt: Copied (new) 2025/01/15 04:06:08 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" 2025/01/15 04:06:08 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "tr2hj63d80ftlmvm6a952snjcc" 2025/01/15 04:06:08 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "jcjl1bv3ep0v8kt35lqql1co90" 2025/01/15 04:06:08 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "qtq2f6qq4lgpsmj88vb7147qje3prudmtfdtr2342fth58vo9a50" 2025/01/15 04:06:08 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k" 2025/01/15 04:06:08 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "qtq2f6qq4lgpsmj88vb7147qje3prudmtfdtr2342fth58vo9a50" 2025/01/15 04:06:08 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "jcjl1bv3ep0v8kt35lqql1co90" --- PASS: TestSyncSuffixKeepExtension (26.50s) === RUN TestSyncUTFNorm run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-wikoqah8fura'", Local "Local file system at /tmp/rclone1597030733", Modify Window "1ms" 2025/01/15 04:06:10 DEBUG : Testêé: md5 = f775d2cd123e4fb3dfe9d57cd3abf563 OK 2025/01/15 04:06:11 DEBUG : Testêé: Sizes differ (src 14 vs dst 18) 2025/01/15 04:06:11 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wikoqah8fura': Waiting for checks to finish 2025/01/15 04:06:11 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wikoqah8fura': Waiting for transfers to finish 2025/01/15 04:06:13 DEBUG : Testêé: md5 = 8933f6a97cbc890b5e739084946c9d13 OK 2025/01/15 04:06:13 INFO : Testêé: Copied (replaced existing) to: Testêé 2025/01/15 04:06:13 DEBUG : Waiting for deletions to finish --- PASS: TestSyncUTFNorm (5.21s) === RUN TestSyncImmutable run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-wikoqah8fura'", Local "Local file system at /tmp/rclone1597030733", Modify Window "1ms" 2025/01/15 04:06:14 DEBUG : existing: Need to transfer - File not found at Destination 2025/01/15 04:06:14 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wikoqah8fura': Waiting for checks to finish 2025/01/15 04:06:14 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wikoqah8fura': Waiting for transfers to finish 2025/01/15 04:06:16 DEBUG : existing: md5 = e5ff6ae05a676a3881956c6ab3d5d388 OK 2025/01/15 04:06:16 INFO : existing: Copied (new) 2025/01/15 04:06:16 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-wikoqah8fura'", Local "Local file system at /tmp/rclone1597030733", Modify Window "1ms" 2025/01/15 04:06:17 DEBUG : existing: Sizes differ (src 8 vs dst 6) 2025/01/15 04:06:17 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wikoqah8fura': Waiting for checks to finish 2025/01/15 04:06:17 ERROR : existing: Source and destination exist but do not match: immutable file modified 2025/01/15 04:06:17 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wikoqah8fura': Waiting for transfers to finish 2025/01/15 04:06:17 ERROR : Encrypted drive 'TestCryptDrive:rclone-test-wikoqah8fura': not deleting files as there were IO errors 2025/01/15 04:06:17 ERROR : Encrypted drive 'TestCryptDrive:rclone-test-wikoqah8fura': not deleting directories as there were IO errors run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-wikoqah8fura'", Local "Local file system at /tmp/rclone1597030733", Modify Window "1ms" --- PASS: TestSyncImmutable (5.17s) === RUN TestSyncIgnoreCase run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-wikoqah8fura'", Local "Local file system at /tmp/rclone1597030733", Modify Window "1ms" 2025/01/15 04:06:21 DEBUG : EXISTING: md5 = 3e19199eb0b8ee4408395531daf0d8c7 OK 2025/01/15 04:06:21 DEBUG : existing: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/01/15 04:06:21 DEBUG : existing: Unchanged skipping 2025/01/15 04:06:21 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wikoqah8fura': Waiting for checks to finish 2025/01/15 04:06:21 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wikoqah8fura': Waiting for transfers to finish 2025/01/15 04:06:21 DEBUG : Waiting for deletions to finish 2025/01/15 04:06:21 INFO : There was nothing to transfer --- PASS: TestSyncIgnoreCase (4.64s) === RUN TestFixCase run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-wikoqah8fura'", Local "Local file system at /tmp/rclone1597030733", Modify Window "1ms" sync_test.go:2635: Skipping test as local or remote are case-sensitive --- SKIP: TestFixCase (0.48s) === RUN TestMaxTransfer === RUN TestMaxTransfer/Hard run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-wikoqah8fura'", Local "Local file system at /tmp/rclone1597030733", 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-wikoqah8fura'", Local "Local file system at /tmp/rclone1597030733", 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-wikoqah8fura'", Local "Local file system at /tmp/rclone1597030733", Modify Window "1ms" sync_test.go:2674: This test only runs on local --- PASS: TestMaxTransfer (1.36s) --- SKIP: TestMaxTransfer/Hard (0.46s) --- SKIP: TestMaxTransfer/Soft (0.44s) --- SKIP: TestMaxTransfer/Cautious (0.46s) === RUN TestSyncConcurrentDelete run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-wikoqah8fura'", Local "Local file system at /tmp/rclone1597030733", Modify Window "1ms" 2025/01/15 04:06:27 DEBUG : both0: md5 = 8c6db790f07a04627c4e5c840c13afc1 OK 2025/01/15 04:06:29 DEBUG : only0: md5 = 11aef63732e07a1bd25ef75f9ad213a7 OK 2025/01/15 04:06:31 DEBUG : both1: md5 = f0bb4757d63e1756a365684433d80b26 OK 2025/01/15 04:06:32 DEBUG : only1: md5 = a4c5608336df462011665d1ad96b86ff OK 2025/01/15 04:06:34 DEBUG : both2: md5 = 23c4e201a33e2c3784fb4e6cd4e9a8ac OK 2025/01/15 04:06:36 DEBUG : only2: md5 = 99ec24dc8043a66b3895178d21a46000 OK 2025/01/15 04:06:37 DEBUG : both3: md5 = dae16701101336a169046d042f2c7173 OK 2025/01/15 04:06:39 DEBUG : only3: md5 = 47b9ffbcf0c68ee440b21668ea3ce80b OK 2025/01/15 04:06:41 DEBUG : both4: md5 = f05f02124ef4e6a73507f7bbaf0f27a4 OK 2025/01/15 04:06:43 DEBUG : only4: md5 = e1b2e92ab1232fe664aeddd96c41e9b4 OK 2025/01/15 04:06:45 DEBUG : both5: md5 = b5cdcf1b835d43c9006b89e96f6903bf OK 2025/01/15 04:06:46 DEBUG : only5: md5 = cb3885e06cde9e617a9b66faa695e86f OK 2025/01/15 04:06:48 DEBUG : both6: md5 = 17a1b0d1902a7141c65d4bf97ef88bc0 OK 2025/01/15 04:06:50 DEBUG : only6: md5 = 69dd22adc2b565a4cc938bdc2b26bd95 OK 2025/01/15 04:06:51 DEBUG : both7: md5 = 9c03cbd0c1b9314746dad0c7be01ca8e OK 2025/01/15 04:06:53 DEBUG : only7: md5 = 93b0027dd487f507537e18f377ba0d8a OK 2025/01/15 04:06:55 DEBUG : both8: md5 = ae23d348146aff937eb1e33ed96d905c OK 2025/01/15 04:06:57 DEBUG : only8: md5 = 53d08bdbbbceb75e60564c6aebeb17aa OK 2025/01/15 04:06:59 DEBUG : both9: md5 = 1274ecd0f4d5665d0743480039167f4b OK 2025/01/15 04:07:00 DEBUG : only9: md5 = e0a0384c4feeb4b4b9b3fe8454cc2119 OK 2025/01/15 04:07:02 DEBUG : both10: md5 = d886c58a71b1589695b166803ace26db OK 2025/01/15 04:07:04 DEBUG : only10: md5 = 12271d67e236a2964aaa827b2e463d49 OK 2025/01/15 04:07:05 DEBUG : both11: md5 = 9cd6269ccd776c5fce1b4ab12d0bdb6b OK 2025/01/15 04:07:07 DEBUG : only11: md5 = 7f8d1cb6ef2940d0557138d2a545e2c5 OK 2025/01/15 04:07:09 DEBUG : both12: md5 = 6b25a5d7b62dd3b78dcf141099656584 OK 2025/01/15 04:07:11 DEBUG : only12: md5 = f2555ab3b435511bf085785d14bafb87 OK 2025/01/15 04:07:12 DEBUG : both13: md5 = ffd9979f71772697a83f6f5ffa8db68c OK 2025/01/15 04:07:14 DEBUG : only13: md5 = 889f331e72ad93668dbbf30b62df97ae OK 2025/01/15 04:07:16 DEBUG : both14: md5 = bd16551bfb543cf6ae09992497d3b0a6 OK 2025/01/15 04:07:17 DEBUG : only14: md5 = 4e8376e4659d90444ddfa89820fde1d2 OK 2025/01/15 04:07:19 DEBUG : both15: md5 = 2c10a1ed89f30900048393e8fe877aa3 OK 2025/01/15 04:07:20 DEBUG : only15: md5 = fe7610e2131e1ed56c0410b066a370d0 OK 2025/01/15 04:07:22 DEBUG : both16: md5 = da2abf9ebd8c56072325f387cbddf8bd OK 2025/01/15 04:07:24 DEBUG : only16: md5 = bc492b98690b2cf6ec208a4313b21d47 OK 2025/01/15 04:07:26 DEBUG : both17: md5 = b6ccbb5d62e35403c54d9d4694271d90 OK 2025/01/15 04:07:28 DEBUG : only17: md5 = a610ac7491067b6cd5641ca7b66d564f OK 2025/01/15 04:07:29 DEBUG : both18: md5 = e46d92e095e72a22018d19936d6d26ec OK 2025/01/15 04:07:31 DEBUG : only18: md5 = 1c855da3de83b306795f47b81931f3b5 OK 2025/01/15 04:07:33 DEBUG : both19: md5 = 0eb7feb3ac86fdb4f484be461e3344e7 OK 2025/01/15 04:07:34 DEBUG : only19: md5 = bf6e9c4b9aedd70c2eb606e12ee6f608 OK 2025/01/15 04:07:35 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wikoqah8fura': Waiting for checks to finish 2025/01/15 04:07:35 DEBUG : both0: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/01/15 04:07:35 DEBUG : both10: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/01/15 04:07:35 DEBUG : both1: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/01/15 04:07:35 DEBUG : both11: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/01/15 04:07:35 DEBUG : both0: Unchanged skipping 2025/01/15 04:07:35 DEBUG : both12: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/01/15 04:07:35 DEBUG : both12: Unchanged skipping 2025/01/15 04:07:35 DEBUG : both13: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/01/15 04:07:35 DEBUG : both13: Unchanged skipping 2025/01/15 04:07:35 DEBUG : both14: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/01/15 04:07:35 DEBUG : both14: Unchanged skipping 2025/01/15 04:07:35 DEBUG : both15: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/01/15 04:07:35 DEBUG : both10: Unchanged skipping 2025/01/15 04:07:35 DEBUG : both16: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/01/15 04:07:35 DEBUG : both16: Unchanged skipping 2025/01/15 04:07:35 DEBUG : both17: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/01/15 04:07:35 DEBUG : both17: Unchanged skipping 2025/01/15 04:07:35 DEBUG : both18: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/01/15 04:07:35 DEBUG : both18: Unchanged skipping 2025/01/15 04:07:35 DEBUG : both19: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/01/15 04:07:35 DEBUG : both19: Unchanged skipping 2025/01/15 04:07:35 DEBUG : both2: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/01/15 04:07:35 DEBUG : both2: Unchanged skipping 2025/01/15 04:07:35 DEBUG : both3: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/01/15 04:07:35 DEBUG : both3: Unchanged skipping 2025/01/15 04:07:35 DEBUG : both4: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/01/15 04:07:35 DEBUG : both4: Unchanged skipping 2025/01/15 04:07:35 DEBUG : both5: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/01/15 04:07:35 DEBUG : both5: Unchanged skipping 2025/01/15 04:07:35 DEBUG : both6: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/01/15 04:07:35 DEBUG : both6: Unchanged skipping 2025/01/15 04:07:35 DEBUG : both7: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/01/15 04:07:35 DEBUG : both7: Unchanged skipping 2025/01/15 04:07:35 DEBUG : both8: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/01/15 04:07:35 DEBUG : both8: Unchanged skipping 2025/01/15 04:07:35 DEBUG : both9: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/01/15 04:07:35 DEBUG : both9: Unchanged skipping 2025/01/15 04:07:35 DEBUG : both1: Unchanged skipping 2025/01/15 04:07:35 DEBUG : both11: Unchanged skipping 2025/01/15 04:07:35 DEBUG : both15: Unchanged skipping 2025/01/15 04:07:35 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wikoqah8fura': Waiting for transfers to finish 2025/01/15 04:07:35 DEBUG : Waiting for deletions to finish 2025/01/15 04:07:36 INFO : only3: Deleted 2025/01/15 04:07:36 INFO : only13: Deleted 2025/01/15 04:07:36 INFO : only16: Deleted 2025/01/15 04:07:36 INFO : only18: Deleted 2025/01/15 04:07:36 INFO : only6: Deleted 2025/01/15 04:07:36 INFO : only0: Deleted 2025/01/15 04:07:36 INFO : only8: Deleted 2025/01/15 04:07:36 INFO : only4: Deleted 2025/01/15 04:07:37 INFO : only1: Deleted 2025/01/15 04:07:37 INFO : only11: Deleted 2025/01/15 04:07:37 INFO : only12: Deleted 2025/01/15 04:07:37 INFO : only15: Deleted 2025/01/15 04:07:37 INFO : only17: Deleted 2025/01/15 04:07:38 INFO : only10: Deleted 2025/01/15 04:07:38 INFO : only5: Deleted 2025/01/15 04:07:38 INFO : only14: Deleted 2025/01/15 04:07:38 INFO : only19: Deleted 2025/01/15 04:07:38 INFO : only2: Deleted 2025/01/15 04:07:38 INFO : only7: Deleted 2025/01/15 04:07:38 INFO : only9: Deleted 2025/01/15 04:07:38 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-wikoqah8fura'", Local "Local file system at /tmp/rclone1597030733", Modify Window "1ms" --- PASS: TestSyncConcurrentDelete (85.62s) === RUN TestSyncConcurrentTruncate run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-wikoqah8fura'", Local "Local file system at /tmp/rclone1597030733", Modify Window "1ms" 2025/01/15 04:07:53 DEBUG : both0: md5 = a2ebebb29039f6bb6f3ae51dd3cfa1e4 OK 2025/01/15 04:07:55 DEBUG : only0: md5 = dd925dae44f6b9caa2b4c4ddb4d4e214 OK 2025/01/15 04:07:56 DEBUG : both1: md5 = 159a1050772d35e6335a5a5471560f3c OK 2025/01/15 04:07:58 DEBUG : only1: md5 = e750eda7dfe80146362a354aa8bc271f OK 2025/01/15 04:08:00 DEBUG : both2: md5 = 81d325cdde3ca3eda961e1bc0b8407d5 OK 2025/01/15 04:08:01 DEBUG : only2: md5 = 86aa63fe575e92623c7952e644ca2353 OK 2025/01/15 04:08:03 DEBUG : both3: md5 = 034e51ba6e72106faeafe3d343ffa8c0 OK 2025/01/15 04:08:05 DEBUG : only3: md5 = c1568deb9472bb19adb4c29126cf4496 OK 2025/01/15 04:08:07 DEBUG : both4: md5 = d4c40c6f60a5cd2f931ac87086ceff68 OK 2025/01/15 04:08:08 DEBUG : only4: md5 = 717f726ac11b078b3c1dcb1c582e2a62 OK 2025/01/15 04:08:10 DEBUG : both5: md5 = a26cbed8217c42a15e01ee923e395072 OK 2025/01/15 04:08:12 DEBUG : only5: md5 = 003c8080c6d7510e0d2bf86ec0746181 OK 2025/01/15 04:08:13 DEBUG : both6: md5 = f7ac2ef4177d6af0efe827c1a3664784 OK 2025/01/15 04:08:15 DEBUG : only6: md5 = e584af6f434e74eec8b180e62bd77bfd OK 2025/01/15 04:08:16 DEBUG : both7: md5 = bf6419051f439046cb0584ac90ee5961 OK 2025/01/15 04:08:18 DEBUG : only7: md5 = 2b60817008396cb651c6c3c9fed27abe OK 2025/01/15 04:08:20 DEBUG : both8: md5 = 227d2d4359de5aca1814bde4018a6780 OK 2025/01/15 04:08:21 DEBUG : only8: md5 = e406ac5eaf24e23049b7f2c2f47acf15 OK 2025/01/15 04:08:23 DEBUG : both9: md5 = 96db53d543f514ba190d296a0d87c761 OK 2025/01/15 04:08:25 DEBUG : only9: md5 = e93cffc047ce5d3f5a3b791d5bebe41e OK 2025/01/15 04:08:27 DEBUG : both10: md5 = 795b3410241d7d02247ae90fedc13459 OK 2025/01/15 04:08:29 DEBUG : only10: md5 = 02e6fd3d16278b361866c4aeba42c273 OK 2025/01/15 04:08:30 DEBUG : both11: md5 = cb5d3238feaa27d2842dabd9ea203ab5 OK 2025/01/15 04:08:32 DEBUG : only11: md5 = abda1f6ab87c3c3ea7dad758944fc84a OK 2025/01/15 04:08:34 DEBUG : both12: md5 = 029f6ef4e2ac8003704af1f48e8e1acd OK 2025/01/15 04:08:35 DEBUG : only12: md5 = c5b99cfb0021c10dd51f47b994abc3f0 OK 2025/01/15 04:08:37 DEBUG : both13: md5 = 9b7d216ab969d50bcc924fa769feb436 OK 2025/01/15 04:08:38 DEBUG : only13: md5 = 066276bd17e9ef04276f8b1accbbc029 OK 2025/01/15 04:08:40 DEBUG : both14: md5 = add062d852a8c2527a889741af6e390c OK 2025/01/15 04:08:42 DEBUG : only14: md5 = bfb290113fdc44322beb4681e761cedb OK 2025/01/15 04:08:44 DEBUG : both15: md5 = 434f73bb0f1efee8efb0dc88abba4236 OK 2025/01/15 04:08:45 DEBUG : only15: md5 = c2299b66eeae5f639a6642f1989f61f9 OK 2025/01/15 04:08:47 DEBUG : both16: md5 = aeb91cf7d3b76d24d079bd3389e6fd71 OK 2025/01/15 04:08:49 DEBUG : only16: md5 = 772c6f1f56e84ffa7e90f2714045f0f4 OK 2025/01/15 04:08:50 DEBUG : both17: md5 = 29cee36d94fe67a6382c53135e3f30ed OK 2025/01/15 04:08:52 DEBUG : only17: md5 = 2660c6c759b71233bc5e5ce36c3feba4 OK 2025/01/15 04:08:54 DEBUG : both18: md5 = ab0494b68bcaf537fb0477137e785c35 OK 2025/01/15 04:08:56 DEBUG : only18: md5 = 72cff5c32c23530b55ee75667571a90c OK 2025/01/15 04:08:58 DEBUG : both19: md5 = acb24ef19c04d629f7fe934a73a7ff2b OK 2025/01/15 04:08:59 DEBUG : only19: md5 = b0527b29f15e14b1eb23c1c3c7f7bfc9 OK 2025/01/15 04:09:00 DEBUG : both0: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/01/15 04:09:00 DEBUG : both1: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/01/15 04:09:00 DEBUG : both11: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/01/15 04:09:00 DEBUG : both10: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/01/15 04:09:00 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wikoqah8fura': Waiting for checks to finish 2025/01/15 04:09:00 DEBUG : both0: Unchanged skipping 2025/01/15 04:09:00 DEBUG : both12: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/01/15 04:09:00 DEBUG : both12: Unchanged skipping 2025/01/15 04:09:00 DEBUG : both13: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/01/15 04:09:00 DEBUG : both13: Unchanged skipping 2025/01/15 04:09:00 DEBUG : both14: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/01/15 04:09:00 DEBUG : both14: Unchanged skipping 2025/01/15 04:09:00 DEBUG : both15: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/01/15 04:09:00 DEBUG : both15: Unchanged skipping 2025/01/15 04:09:00 DEBUG : both16: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/01/15 04:09:00 DEBUG : both1: Unchanged skipping 2025/01/15 04:09:00 DEBUG : both17: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/01/15 04:09:00 DEBUG : both11: Unchanged skipping 2025/01/15 04:09:00 DEBUG : both18: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/01/15 04:09:00 DEBUG : both18: Unchanged skipping 2025/01/15 04:09:00 DEBUG : both19: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/01/15 04:09:00 DEBUG : both19: Unchanged skipping 2025/01/15 04:09:00 DEBUG : both2: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/01/15 04:09:00 DEBUG : both10: Unchanged skipping 2025/01/15 04:09:00 DEBUG : both3: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/01/15 04:09:00 DEBUG : both16: Unchanged skipping 2025/01/15 04:09:00 DEBUG : both4: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/01/15 04:09:00 DEBUG : both17: Unchanged skipping 2025/01/15 04:09:00 DEBUG : both5: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/01/15 04:09:00 DEBUG : both5: Unchanged skipping 2025/01/15 04:09:00 DEBUG : both6: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/01/15 04:09:00 DEBUG : both6: Unchanged skipping 2025/01/15 04:09:00 DEBUG : both7: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/01/15 04:09:00 DEBUG : both7: Unchanged skipping 2025/01/15 04:09:00 DEBUG : both8: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/01/15 04:09:00 DEBUG : both8: Unchanged skipping 2025/01/15 04:09:00 DEBUG : both9: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/01/15 04:09:00 DEBUG : both9: Unchanged skipping 2025/01/15 04:09:00 DEBUG : only0: Sizes differ (src 0 vs dst 6) 2025/01/15 04:09:00 DEBUG : only1: Sizes differ (src 0 vs dst 6) 2025/01/15 04:09:00 DEBUG : only10: Sizes differ (src 0 vs dst 6) 2025/01/15 04:09:00 DEBUG : both2: Unchanged skipping 2025/01/15 04:09:00 DEBUG : only11: Sizes differ (src 0 vs dst 6) 2025/01/15 04:09:00 DEBUG : both3: Unchanged skipping 2025/01/15 04:09:00 DEBUG : only12: Sizes differ (src 0 vs dst 6) 2025/01/15 04:09:00 DEBUG : both4: Unchanged skipping 2025/01/15 04:09:00 DEBUG : only13: Sizes differ (src 0 vs dst 6) 2025/01/15 04:09:00 DEBUG : only14: Sizes differ (src 0 vs dst 6) 2025/01/15 04:09:00 DEBUG : only15: Sizes differ (src 0 vs dst 6) 2025/01/15 04:09:00 DEBUG : only16: Sizes differ (src 0 vs dst 6) 2025/01/15 04:09:00 DEBUG : only17: Sizes differ (src 0 vs dst 6) 2025/01/15 04:09:00 DEBUG : only18: Sizes differ (src 0 vs dst 6) 2025/01/15 04:09:00 DEBUG : only19: Sizes differ (src 0 vs dst 6) 2025/01/15 04:09:00 DEBUG : only2: Sizes differ (src 0 vs dst 6) 2025/01/15 04:09:00 DEBUG : only3: Sizes differ (src 0 vs dst 6) 2025/01/15 04:09:00 DEBUG : only4: Sizes differ (src 0 vs dst 6) 2025/01/15 04:09:00 DEBUG : only5: Sizes differ (src 0 vs dst 6) 2025/01/15 04:09:00 DEBUG : only6: Sizes differ (src 0 vs dst 6) 2025/01/15 04:09:00 DEBUG : only7: Sizes differ (src 0 vs dst 6) 2025/01/15 04:09:00 DEBUG : only8: Sizes differ (src 0 vs dst 6) 2025/01/15 04:09:00 DEBUG : only9: Sizes differ (src 0 vs dst 6) 2025/01/15 04:09:00 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wikoqah8fura': Waiting for transfers to finish 2025/01/15 04:09:01 DEBUG : only13: md5 = 865145afaab1cbadd84542df19cc4db5 OK 2025/01/15 04:09:01 INFO : only13: Copied (replaced existing) 2025/01/15 04:09:01 DEBUG : only1: md5 = 8f150ea24ad7701264473c47328a7bf1 OK 2025/01/15 04:09:01 INFO : only1: Copied (replaced existing) 2025/01/15 04:09:01 DEBUG : only0: md5 = 225f4537d92c48f57d3503f211cc4ed8 OK 2025/01/15 04:09:01 INFO : only0: Copied (replaced existing) 2025/01/15 04:09:01 DEBUG : only10: md5 = a96ec765e0ce9f8d095ae7090d3287d3 OK 2025/01/15 04:09:01 INFO : only10: Copied (replaced existing) 2025/01/15 04:09:03 DEBUG : only11: md5 = 11b99fc460c5a72028146b1562326c69 OK 2025/01/15 04:09:03 INFO : only11: Copied (replaced existing) 2025/01/15 04:09:03 DEBUG : only12: md5 = 8709957c49964ece7b622df3b62234e2 OK 2025/01/15 04:09:03 INFO : only12: Copied (replaced existing) 2025/01/15 04:09:03 DEBUG : only17: md5 = c7503058f41844a8c006085fd4e2797c OK 2025/01/15 04:09:03 INFO : only17: Copied (replaced existing) 2025/01/15 04:09:03 DEBUG : only14: md5 = f0094639aba34bcef097fc4041bfc42e OK 2025/01/15 04:09:03 INFO : only14: Copied (replaced existing) 2025/01/15 04:09:04 DEBUG : only16: md5 = 04fdbefcd5fd35f8ab12c8817af5e32d OK 2025/01/15 04:09:04 INFO : only16: Copied (replaced existing) 2025/01/15 04:09:04 DEBUG : only15: md5 = ffdfa22414e33c630e86cf403e6c8296 OK 2025/01/15 04:09:04 INFO : only15: Copied (replaced existing) 2025/01/15 04:09:04 DEBUG : only18: md5 = 891211f5fc961846e2a44df91d86335c OK 2025/01/15 04:09:04 INFO : only18: Copied (replaced existing) 2025/01/15 04:09:04 DEBUG : only4: md5 = 5c32dcf6e0f691fc650fa5adc7d08eb0 OK 2025/01/15 04:09:04 INFO : only4: Copied (replaced existing) 2025/01/15 04:09:05 DEBUG : only5: md5 = 94fbb983d457739d7c4341134edc5f96 OK 2025/01/15 04:09:05 INFO : only5: Copied (replaced existing) 2025/01/15 04:09:05 DEBUG : only6: md5 = 281b6532b0aa25921ea6b7769c5f9ece OK 2025/01/15 04:09:05 INFO : only6: Copied (replaced existing) 2025/01/15 04:09:05 DEBUG : only19: md5 = e286dc5c24c253cd2418a84ac63f4905 OK 2025/01/15 04:09:05 INFO : only19: Copied (replaced existing) 2025/01/15 04:09:05 DEBUG : only8: md5 = c97a67ca42c5209ede2931a4fc2ad856 OK 2025/01/15 04:09:05 INFO : only8: Copied (replaced existing) 2025/01/15 04:09:07 DEBUG : only3: md5 = c34e471e761f81c4e461e9e7d1af72be OK 2025/01/15 04:09:07 INFO : only3: Copied (replaced existing) 2025/01/15 04:09:07 DEBUG : only2: md5 = 9bc7e3c2d1196ecb83807224b3347d95 OK 2025/01/15 04:09:07 INFO : only2: Copied (replaced existing) 2025/01/15 04:09:07 DEBUG : only7: md5 = f93e36c614139637a7c1984c9eaa9ab8 OK 2025/01/15 04:09:07 INFO : only7: Copied (replaced existing) 2025/01/15 04:09:07 DEBUG : only9: md5 = 0f10d3e8e3eb5e0f7e97cafbc698ee6c OK 2025/01/15 04:09:07 INFO : only9: Copied (replaced existing) 2025/01/15 04:09:07 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-wikoqah8fura'", Local "Local file system at /tmp/rclone1597030733", Modify Window "1ms" --- PASS: TestSyncConcurrentTruncate (101.01s) === RUN TestNothingToTransferWithEmptyDirs run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-wikoqah8fura'", Local "Local file system at /tmp/rclone1597030733", Modify Window "1ms" 2025/01/15 04:09:32 INFO : sub dir: Set directory modification time (using DirSetModTime) 2025/01/15 04:09:32 DEBUG : sub dir: Making directory with metadata 2025/01/15 04:09:33 INFO : sub dir: Made directory with metadata (mtime=2011-12-30T12:59:59Z) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-wikoqah8fura'", Local "Local file system at /tmp/rclone1597030733", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-wikoqah8fura'", Local "Local file system at /tmp/rclone1597030733", Modify Window "1ms" 2025/01/15 04:09:54 INFO : sub dir2: Set directory modification time (using DirSetModTime) 2025/01/15 04:09:55 INFO : sub dir2: Set directory modification time (using DirSetModTime) 2025/01/15 04:09:55 INFO : sub dirEmpty/sub dirEmpty2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2025/01/15 04:09:55 INFO : sub dirEmpty: Set directory modification time (using DirSetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-wikoqah8fura'", Local "Local file system at /tmp/rclone1597030733", Modify Window "1ms" 2025/01/15 04:10:11 DEBUG : gcsdkq814sbtppue42dpsbg8ug: Rmdir: contains trashed file: "sjuo65gk5q3r1199jselk9k9o0" 2025/01/15 04:10:11 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/37qp6d1gohacv723ij3brofbu8/i24n0ln37pa2hv8pctddeuh73o: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" 2025/01/15 04:10:13 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/37qp6d1gohacv723ij3brofbu8: Rmdir: contains trashed file: "i24n0ln37pa2hv8pctddeuh73o" 2025/01/15 04:10:14 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "37qp6d1gohacv723ij3brofbu8" 2025/01/15 04:10:14 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak" 2025/01/15 04:10:15 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak" 2025/01/15 04:10:16 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak" 2025/01/15 04:10:17 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak" 2025/01/15 04:10:18 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/4r13oncfa2rsrr82oqhsqv24ns: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" 2025/01/15 04:10:19 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc: Rmdir: contains trashed file: "4r13oncfa2rsrr82oqhsqv24ns" 2025/01/15 04:10:19 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak" 2025/01/15 04:10:20 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestNothingToTransferWithEmptyDirs (50.02s) === RUN TestNothingToTransferWithoutEmptyDirs run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-wikoqah8fura'", Local "Local file system at /tmp/rclone1597030733", Modify Window "1ms" 2025/01/15 04:10:22 INFO : sub dir: Set directory modification time (using DirSetModTime) 2025/01/15 04:10:22 DEBUG : sub dir: Making directory with metadata 2025/01/15 04:10:24 INFO : sub dir: Made directory with metadata (mtime=2011-12-30T12:59:59Z) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-wikoqah8fura'", Local "Local file system at /tmp/rclone1597030733", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-wikoqah8fura'", Local "Local file system at /tmp/rclone1597030733", Modify Window "1ms" 2025/01/15 04:10:49 INFO : sub dir2: Set directory modification time (using DirSetModTime) 2025/01/15 04:10:50 INFO : sub dir2: Set directory modification time (using DirSetModTime) 2025/01/15 04:10:50 INFO : sub dirEmpty/sub dirEmpty2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2025/01/15 04:10:50 INFO : sub dirEmpty: Set directory modification time (using DirSetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-wikoqah8fura'", Local "Local file system at /tmp/rclone1597030733", Modify Window "1ms" 2025/01/15 04:11:04 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/37qp6d1gohacv723ij3brofbu8/i24n0ln37pa2hv8pctddeuh73o: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" 2025/01/15 04:11:05 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/37qp6d1gohacv723ij3brofbu8: Rmdir: contains trashed file: "i24n0ln37pa2hv8pctddeuh73o" 2025/01/15 04:11:06 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "37qp6d1gohacv723ij3brofbu8" 2025/01/15 04:11:07 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak" 2025/01/15 04:11:08 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak" 2025/01/15 04:11:09 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak" 2025/01/15 04:11:10 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak" 2025/01/15 04:11:11 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/4r13oncfa2rsrr82oqhsqv24ns: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" 2025/01/15 04:11:12 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc: Rmdir: contains trashed file: "4r13oncfa2rsrr82oqhsqv24ns" 2025/01/15 04:11:12 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak" 2025/01/15 04:11:13 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestNothingToTransferWithoutEmptyDirs (52.92s) PASS 2025/01/15 04:11:15 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-wikoqah8fura': Purge remote "./sync.test -test.v -test.timeout 1h0m0s -remote TestCryptDrive: -verbose -fast-list" - Finished OK in 17m55.109821015s (try 1/5)