"./sync.test -test.v -test.timeout 1h0m0s -remote TestCryptDrive: -verbose -fast-list" - Starting (try 1/5) 2025/01/31 01:52:58 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-payebeb7toku" 2025/01/31 01:52:58 DEBUG : Using config file from "/home/rclone/.rclone.conf" 2025/01/31 01:52:58 DEBUG : Creating backend with remote "TestDrive:crypt/3s78bg6469de2de4o25i2dbql3rcb1o5fblcj0r3fdq18f6qbclg" 2025/01/31 01:52:59 DEBUG : Creating backend with remote "/tmp/rclone695105756" === RUN TestPipe --- PASS: TestPipe (0.00s) === RUN TestPipeConcurrent --- PASS: TestPipeConcurrent (0.03s) === 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-payebeb7toku'", Local "Local file system at /tmp/rclone695105756", Modify Window "1ms" 2025/01/31 01:53:01 DEBUG : Added delayed dir = "sub dir", newDst= 2025/01/31 01:53:01 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2025/01/31 01:53:01 NOTICE: sub dir/hello world: Skipped copy as --dry-run is set (size 11) 2025/01/31 01:53:01 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-payebeb7toku': Waiting for checks to finish 2025/01/31 01:53:01 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-payebeb7toku': Waiting for transfers to finish 2025/01/31 01:53:01 NOTICE: sub dir: Skipped set directory modification time as --dry-run is set run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-payebeb7toku'", Local "Local file system at /tmp/rclone695105756", Modify Window "1ms" --- PASS: TestCopyWithDryRun (2.41s) === RUN TestCopy run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-payebeb7toku'", Local "Local file system at /tmp/rclone695105756", Modify Window "1ms" 2025/01/31 01:53:02 INFO : sub dir: Set directory modification time (using DirSetModTime) 2025/01/31 01:53:02 DEBUG : Added delayed dir = "sub dir", newDst= 2025/01/31 01:53:02 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2025/01/31 01:53:02 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-payebeb7toku': Waiting for checks to finish 2025/01/31 01:53:02 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-payebeb7toku': Waiting for transfers to finish 2025/01/31 01:53:05 DEBUG : sub dir/hello world: md5 = cf0be42b75b45f448fb49ddcdfaed0e3 OK 2025/01/31 01:53:05 INFO : sub dir/hello world: Copied (new) 2025/01/31 01:53:05 INFO : sub dir: Set directory modification time (using DirSetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-payebeb7toku'", Local "Local file system at /tmp/rclone695105756", Modify Window "1ms" 2025/01/31 01:53:07 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestCopy (6.61s) === RUN TestCopyMetadata run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-payebeb7toku'", Local "Local file system at /tmp/rclone695105756", Modify Window "1ms" 2025/01/31 01:53:08 DEBUG : metadata sub dir: Making directory with metadata 2025/01/31 01:53:08 INFO : metadata sub dir: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2025/01/31 01:53:08 DEBUG : empty metadata sub dir: Making directory with metadata 2025/01/31 01:53:08 INFO : empty metadata sub dir: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2025/01/31 01:53:08 DEBUG : Local file system at /tmp/rclone695105756: File to upload is small (21 bytes), uploading instead of streaming 2025/01/31 01:53:08 DEBUG : metadata sub dir/hello metadata world: md5 = baa7a013449dbba2b1ed02b5cfb4e1a2 OK 2025/01/31 01:53:08 DEBUG : metadata sub dir/hello metadata world: Size and md5 of src and dst objects identical 2025/01/31 01:53:08 INFO : metadata sub dir: Set directory modification time (using DirSetModTime) 2025/01/31 01:53:09 DEBUG : Google drive root 'crypt/3s78bg6469de2de4o25i2dbql3rcb1o5fblcj0r3fdq18f6qbclg': Skipping btime metadata as can't update it on an existing file: 2025-01-31T01:53:08.812100414Z 2025/01/31 01:53:10 INFO : empty metadata sub dir: Updated directory metadata 2025/01/31 01:53:10 DEBUG : Google drive root 'crypt/3s78bg6469de2de4o25i2dbql3rcb1o5fblcj0r3fdq18f6qbclg': Skipping btime metadata as can't update it on an existing file: 2025-01-31T01:53:08.812100414Z 2025/01/31 01:53:11 INFO : metadata sub dir: Updated directory metadata 2025/01/31 01:53:11 DEBUG : metadata sub dir/hello metadata world: Need to transfer - File not found at Destination 2025/01/31 01:53:11 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-payebeb7toku': Waiting for checks to finish 2025/01/31 01:53:11 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-payebeb7toku': Waiting for transfers to finish 2025/01/31 01:53:12 DEBUG : metadata sub dir/hello metadata world: md5 = f8549d46a4a64bcae8b938b71854325d OK 2025/01/31 01:53:12 INFO : metadata sub dir/hello metadata world: Copied (new) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-payebeb7toku'", Local "Local file system at /tmp/rclone695105756", Modify Window "1ms" 2025/01/31 01:53:15 DEBUG : fg45q1rm3kh00nmmkk4m6ihmrcnel1p7551kqhjr9bk2gtd2gbf0: Rmdir: contains trashed file: "dmuvulfij81f693ur0f1vvbvq9v6iscp56daas3m51n9li5e3470" --- PASS: TestCopyMetadata (8.94s) === RUN TestCopyMetadataNoEmptyDirs run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-payebeb7toku'", Local "Local file system at /tmp/rclone695105756", Modify Window "1ms" 2025/01/31 01:53:17 DEBUG : metadata sub dir: Making directory with metadata 2025/01/31 01:53:17 INFO : metadata sub dir: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2025/01/31 01:53:17 DEBUG : empty metadata sub dir: Making directory with metadata 2025/01/31 01:53:17 INFO : empty metadata sub dir: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2025/01/31 01:53:17 DEBUG : Local file system at /tmp/rclone695105756: File to upload is small (21 bytes), uploading instead of streaming 2025/01/31 01:53:17 DEBUG : metadata sub dir/hello metadata world: md5 = baa7a013449dbba2b1ed02b5cfb4e1a2 OK 2025/01/31 01:53:17 DEBUG : metadata sub dir/hello metadata world: Size and md5 of src and dst objects identical 2025/01/31 01:53:17 INFO : metadata sub dir: Set directory modification time (using DirSetModTime) 2025/01/31 01:53:17 DEBUG : Added delayed dir = "empty metadata sub dir", newDst= 2025/01/31 01:53:17 DEBUG : Added delayed dir = "metadata sub dir", newDst= 2025/01/31 01:53:17 DEBUG : metadata sub dir/hello metadata world: Need to transfer - File not found at Destination 2025/01/31 01:53:17 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-payebeb7toku': Waiting for checks to finish 2025/01/31 01:53:17 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-payebeb7toku': Waiting for transfers to finish 2025/01/31 01:53:20 DEBUG : metadata sub dir/hello metadata world: md5 = d63756f1b8c4e9342b923e091c1f8ff3 OK 2025/01/31 01:53:20 INFO : metadata sub dir/hello metadata world: Copied (new) 2025/01/31 01:53:20 DEBUG : Google drive root 'crypt/3s78bg6469de2de4o25i2dbql3rcb1o5fblcj0r3fdq18f6qbclg': Skipping btime metadata as can't update it on an existing file: 2025-01-31T01:53:17.752036859Z 2025/01/31 01:53:21 INFO : metadata sub dir: Updated directory metadata run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-payebeb7toku'", Local "Local file system at /tmp/rclone695105756", Modify Window "1ms" 2025/01/31 01:53:24 DEBUG : fg45q1rm3kh00nmmkk4m6ihmrcnel1p7551kqhjr9bk2gtd2gbf0: Rmdir: contains trashed file: "dmuvulfij81f693ur0f1vvbvq9v6iscp56daas3m51n9li5e3470" --- PASS: TestCopyMetadataNoEmptyDirs (7.53s) === RUN TestCopyMissingDirectory run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-payebeb7toku'", Local "Local file system at /tmp/rclone695105756", Modify Window "1ms" 2025/01/31 01:53:25 DEBUG : Creating backend with remote "/non-existing" 2025/01/31 01:53:25 ERROR : Local file system at /non-existing: error reading source root directory: directory not found 2025/01/31 01:53:25 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-payebeb7toku': Waiting for checks to finish 2025/01/31 01:53:25 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-payebeb7toku': Waiting for transfers to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-payebeb7toku'", Local "Local file system at /tmp/rclone695105756", Modify Window "1ms" --- PASS: TestCopyMissingDirectory (1.08s) === RUN TestCopyNoTraverse run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-payebeb7toku'", Local "Local file system at /tmp/rclone695105756", Modify Window "1ms" 2025/01/31 01:53:26 DEBUG : Added delayed dir = "sub dir", newDst= 2025/01/31 01:53:26 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2025/01/31 01:53:26 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-payebeb7toku': Waiting for checks to finish 2025/01/31 01:53:26 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-payebeb7toku': Waiting for transfers to finish 2025/01/31 01:53:29 DEBUG : sub dir/hello world: md5 = 3723ba38b35ec0c3d8ee9279488cec13 OK 2025/01/31 01:53:29 INFO : sub dir/hello world: Copied (new) 2025/01/31 01:53:29 INFO : sub dir: Set directory modification time (using DirSetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-payebeb7toku'", Local "Local file system at /tmp/rclone695105756", Modify Window "1ms" 2025/01/31 01:53:31 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestCopyNoTraverse (6.44s) === RUN TestCopyCheckFirst run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-payebeb7toku'", Local "Local file system at /tmp/rclone695105756", Modify Window "1ms" 2025/01/31 01:53:32 INFO : Encrypted drive 'TestCryptDrive:rclone-test-payebeb7toku': Running all checks before starting transfers 2025/01/31 01:53:33 DEBUG : Added delayed dir = "sub dir", newDst= 2025/01/31 01:53:33 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2025/01/31 01:53:33 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-payebeb7toku': Waiting for checks to finish 2025/01/31 01:53:33 INFO : Encrypted drive 'TestCryptDrive:rclone-test-payebeb7toku': Checks finished, now starting transfers 2025/01/31 01:53:33 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-payebeb7toku': Waiting for transfers to finish 2025/01/31 01:53:35 DEBUG : sub dir/hello world: md5 = 4d2ba174787000dca444bd905971ac7f OK 2025/01/31 01:53:35 INFO : sub dir/hello world: Copied (new) 2025/01/31 01:53:36 INFO : sub dir: Set directory modification time (using DirSetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-payebeb7toku'", Local "Local file system at /tmp/rclone695105756", Modify Window "1ms" 2025/01/31 01:53:38 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestCopyCheckFirst (6.59s) === RUN TestSyncNoTraverse run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-payebeb7toku'", Local "Local file system at /tmp/rclone695105756", Modify Window "1ms" 2025/01/31 01:53:39 ERROR : Ignoring --no-traverse with sync 2025/01/31 01:53:39 DEBUG : Added delayed dir = "sub dir", newDst= 2025/01/31 01:53:39 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2025/01/31 01:53:39 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-payebeb7toku': Waiting for checks to finish 2025/01/31 01:53:39 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-payebeb7toku': Waiting for transfers to finish 2025/01/31 01:53:41 DEBUG : sub dir/hello world: md5 = 68f755a7b18cd81a596e5b2c4c20f7a4 OK 2025/01/31 01:53:41 INFO : sub dir/hello world: Copied (new) 2025/01/31 01:53:41 DEBUG : Waiting for deletions to finish 2025/01/31 01:53:42 INFO : sub dir: Set directory modification time (using DirSetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-payebeb7toku'", Local "Local file system at /tmp/rclone695105756", Modify Window "1ms" 2025/01/31 01:53:44 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestSyncNoTraverse (6.41s) === RUN TestCopyWithDepth run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-payebeb7toku'", Local "Local file system at /tmp/rclone695105756", Modify Window "1ms" 2025/01/31 01:53:46 DEBUG : hello world2: Need to transfer - File not found at Destination 2025/01/31 01:53:46 DEBUG : Added delayed dir = "sub dir", newDst= 2025/01/31 01:53:46 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-payebeb7toku': Waiting for checks to finish 2025/01/31 01:53:46 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-payebeb7toku': Waiting for transfers to finish 2025/01/31 01:53:47 DEBUG : hello world2: md5 = 364c485ecbe225b82a5f9f0e4bd21966 OK 2025/01/31 01:53:47 INFO : hello world2: Copied (new) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-payebeb7toku'", Local "Local file system at /tmp/rclone695105756", Modify Window "1ms" --- PASS: TestCopyWithDepth (3.60s) === RUN TestCopyWithFilesFrom run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-payebeb7toku'", Local "Local file system at /tmp/rclone695105756", Modify Window "1ms" 2025/01/31 01:53:49 DEBUG : potato2: Need to transfer - File not found at Destination 2025/01/31 01:53:49 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-payebeb7toku': Waiting for checks to finish 2025/01/31 01:53:49 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-payebeb7toku': Waiting for transfers to finish 2025/01/31 01:53:51 DEBUG : potato2: md5 = 407c2b63920d0b5b382986ca68f5913e OK 2025/01/31 01:53:51 INFO : potato2: Copied (new) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-payebeb7toku'", Local "Local file system at /tmp/rclone695105756", Modify Window "1ms" --- PASS: TestCopyWithFilesFrom (3.48s) === RUN TestCopyWithFilesFromAndNoTraverse run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-payebeb7toku'", Local "Local file system at /tmp/rclone695105756", Modify Window "1ms" 2025/01/31 01:53:53 DEBUG : potato2: Need to transfer - File not found at Destination 2025/01/31 01:53:53 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-payebeb7toku': Waiting for checks to finish 2025/01/31 01:53:53 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-payebeb7toku': Waiting for transfers to finish 2025/01/31 01:53:54 DEBUG : potato2: md5 = 767dec376edfc98edfd35f091b095f66 OK 2025/01/31 01:53:54 INFO : potato2: Copied (new) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-payebeb7toku'", Local "Local file system at /tmp/rclone695105756", Modify Window "1ms" --- PASS: TestCopyWithFilesFromAndNoTraverse (3.54s) === RUN TestCopyEmptyDirectories run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-payebeb7toku'", Local "Local file system at /tmp/rclone695105756", Modify Window "1ms" 2025/01/31 01:53:56 DEBUG : sub dir2/sub sub dir2: Making directory with metadata 2025/01/31 01:53:56 INFO : sub dir2/sub sub dir2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2025/01/31 01:53:56 INFO : sub dir2: Set directory modification time (using DirSetModTime) 2025/01/31 01:53:56 INFO : sub dir: Set directory modification time (using DirSetModTime) 2025/01/31 01:53:56 DEBUG : sub dir: Making directory with metadata 2025/01/31 01:53:57 INFO : sub dir: Made directory with metadata (mtime=2001-02-03T04:05:06.499999999Z) 2025/01/31 01:53:57 DEBUG : sub dir2: Making directory with metadata 2025/01/31 01:53:58 INFO : sub dir2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2025/01/31 01:53:58 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2025/01/31 01:53:58 DEBUG : sub dir2/sub sub dir2: Making directory with metadata 2025/01/31 01:53:59 INFO : sub dir2/sub sub dir2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2025/01/31 01:53:59 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-payebeb7toku': Waiting for checks to finish 2025/01/31 01:53:59 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-payebeb7toku': Waiting for transfers to finish 2025/01/31 01:54:00 DEBUG : sub dir/hello world: md5 = 269939675451a0b2da1328c5950d7ccd OK 2025/01/31 01:54:00 INFO : sub dir/hello world: Copied (new) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-payebeb7toku'", Local "Local file system at /tmp/rclone695105756", Modify Window "1ms" 2025/01/31 01:54:04 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc: Rmdir: contains trashed file: "cv6a9uf28ngrajena8kt5ijjn0" 2025/01/31 01:54:04 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestCopyEmptyDirectories (9.73s) === RUN TestCopyNoEmptyDirectories run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-payebeb7toku'", Local "Local file system at /tmp/rclone695105756", Modify Window "1ms" 2025/01/31 01:54:06 INFO : sub dir2: Making directory 2025/01/31 01:54:06 DEBUG : sub dir2/sub sub dir2: Making directory with metadata 2025/01/31 01:54:06 INFO : sub dir2/sub sub dir2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2025/01/31 01:54:06 DEBUG : Added delayed dir = "sub dir", newDst= 2025/01/31 01:54:06 DEBUG : Added delayed dir = "sub dir2", newDst= 2025/01/31 01:54:06 DEBUG : Added delayed dir = "sub dir2/sub sub dir2", newDst= 2025/01/31 01:54:06 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2025/01/31 01:54:06 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-payebeb7toku': Waiting for checks to finish 2025/01/31 01:54:06 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-payebeb7toku': Waiting for transfers to finish 2025/01/31 01:54:09 DEBUG : sub dir/hello world: md5 = 8cddc310800187273c04c2f0c703619f OK 2025/01/31 01:54:09 INFO : sub dir/hello world: Copied (new) 2025/01/31 01:54:09 INFO : sub dir: Set directory modification time (using DirSetModTime) 2025/01/31 01:54:11 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestCopyNoEmptyDirectories (6.27s) === RUN TestMoveEmptyDirectories run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-payebeb7toku'", Local "Local file system at /tmp/rclone695105756", Modify Window "1ms" 2025/01/31 01:54:12 DEBUG : sub dir2: Making directory with metadata 2025/01/31 01:54:12 INFO : sub dir2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2025/01/31 01:54:12 DEBUG : sub dir: Making directory with metadata 2025/01/31 01:54:13 INFO : sub dir: Made directory with metadata (mtime=2025-01-31T01:54:12.423648281Z) 2025/01/31 01:54:13 DEBUG : sub dir2: Making directory with metadata 2025/01/31 01:54:14 INFO : sub dir2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2025/01/31 01:54:14 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2025/01/31 01:54:14 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-payebeb7toku': Waiting for checks to finish 2025/01/31 01:54:14 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-payebeb7toku': Waiting for transfers to finish 2025/01/31 01:54:16 DEBUG : sub dir/hello world: md5 = dd80e69b3a3b6e446b6ae914fae8f03e OK 2025/01/31 01:54:16 INFO : sub dir/hello world: Copied (new) 2025/01/31 01:54:16 INFO : sub dir/hello world: Deleted run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-payebeb7toku'", Local "Local file system at /tmp/rclone695105756", Modify Window "1ms" 2025/01/31 01:54:19 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestMoveEmptyDirectories (8.14s) === RUN TestSyncNoUpdateDirModtime run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-payebeb7toku'", Local "Local file system at /tmp/rclone695105756", Modify Window "1ms" 2025/01/31 01:54:20 DEBUG : sub dir no update dir modtime: Making directory with metadata 2025/01/31 01:54:20 INFO : sub dir no update dir modtime: Made directory with metadata (mtime=2001-02-03T04:05:06.499999999Z) 2025/01/31 01:54:22 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-payebeb7toku': Waiting for checks to finish 2025/01/31 01:54:22 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-payebeb7toku': Waiting for transfers to finish 2025/01/31 01:54:22 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-payebeb7toku'", Local "Local file system at /tmp/rclone695105756", Modify Window "1ms" --- PASS: TestSyncNoUpdateDirModtime (4.24s) === RUN TestMoveNoEmptyDirectories run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-payebeb7toku'", Local "Local file system at /tmp/rclone695105756", Modify Window "1ms" 2025/01/31 01:54:24 INFO : sub dir2: Making directory 2025/01/31 01:54:25 DEBUG : Added delayed dir = "sub dir", newDst= 2025/01/31 01:54:25 DEBUG : Added delayed dir = "sub dir2", newDst= 2025/01/31 01:54:25 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2025/01/31 01:54:25 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-payebeb7toku': Waiting for checks to finish 2025/01/31 01:54:25 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-payebeb7toku': Waiting for transfers to finish 2025/01/31 01:54:27 DEBUG : sub dir/hello world: md5 = ff45b179f1df6a7a92e46d76dd82e9c6 OK 2025/01/31 01:54:27 INFO : sub dir/hello world: Copied (new) 2025/01/31 01:54:27 INFO : sub dir/hello world: Deleted 2025/01/31 01:54:28 INFO : sub dir: Set directory modification time (using DirSetModTime) 2025/01/31 01:54:30 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestMoveNoEmptyDirectories (6.21s) === RUN TestSyncEmptyDirectories run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-payebeb7toku'", Local "Local file system at /tmp/rclone695105756", Modify Window "1ms" 2025/01/31 01:54:31 DEBUG : sub dir2: Making directory with metadata 2025/01/31 01:54:31 INFO : sub dir2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2025/01/31 01:54:31 INFO : sub dir: Set directory modification time (using DirSetModTime) 2025/01/31 01:54:31 DEBUG : sub dir: Making directory with metadata 2025/01/31 01:54:32 INFO : sub dir: Made directory with metadata (mtime=2001-02-03T04:05:06.499999999Z) 2025/01/31 01:54:32 DEBUG : sub dir2: Making directory with metadata 2025/01/31 01:54:33 INFO : sub dir2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2025/01/31 01:54:33 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2025/01/31 01:54:33 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-payebeb7toku': Waiting for checks to finish 2025/01/31 01:54:33 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-payebeb7toku': Waiting for transfers to finish 2025/01/31 01:54:35 DEBUG : sub dir/hello world: md5 = 8874546795c6057ed4a619dcfc7e7952 OK 2025/01/31 01:54:35 INFO : sub dir/hello world: Copied (new) 2025/01/31 01:54:35 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-payebeb7toku'", Local "Local file system at /tmp/rclone695105756", Modify Window "1ms" 2025/01/31 01:54:38 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestSyncEmptyDirectories (8.30s) === RUN TestSyncSetDelayedModTimes run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-payebeb7toku'", Local "Local file system at /tmp/rclone695105756", Modify Window "1ms" sync_test.go:507: Backend doesn't have DirModTimeUpdatesOnWrite set --- SKIP: TestSyncSetDelayedModTimes (0.44s) === RUN TestSyncNoEmptyDirectories run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-payebeb7toku'", Local "Local file system at /tmp/rclone695105756", Modify Window "1ms" 2025/01/31 01:54:39 INFO : sub dir2: Making directory 2025/01/31 01:54:39 DEBUG : Added delayed dir = "sub dir", newDst= 2025/01/31 01:54:39 DEBUG : Added delayed dir = "sub dir2", newDst= 2025/01/31 01:54:39 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2025/01/31 01:54:39 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-payebeb7toku': Waiting for checks to finish 2025/01/31 01:54:39 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-payebeb7toku': Waiting for transfers to finish 2025/01/31 01:54:42 DEBUG : sub dir/hello world: md5 = a41b9eafa754c4a1c53492d14d3d6c2a OK 2025/01/31 01:54:42 INFO : sub dir/hello world: Copied (new) 2025/01/31 01:54:42 DEBUG : Waiting for deletions to finish 2025/01/31 01:54:43 INFO : sub dir: Set directory modification time (using DirSetModTime) 2025/01/31 01:54:45 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestSyncNoEmptyDirectories (6.22s) === RUN TestServerSideCopy run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-payebeb7toku'", Local "Local file system at /tmp/rclone695105756", Modify Window "1ms" 2025/01/31 01:54:48 DEBUG : sub dir/hello world: md5 = 83e019d142e651eeef429262479d7ae3 OK 2025/01/31 01:54:49 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-hogigej4heme" 2025/01/31 01:54:49 DEBUG : Config file has changed externally - reloading 2025/01/31 01:54:49 DEBUG : Creating backend with remote "TestDrive:crypt/k13sp9d6u7p38m3h736qeukone52ptgem080beiu2sm01uocr0og" sync_test.go:590: Server side copy (if possible) Encrypted drive 'TestCryptDrive:rclone-test-payebeb7toku' -> Encrypted drive 'TestCryptDrive:rclone-test-hogigej4heme' 2025/01/31 01:54:50 DEBUG : Added delayed dir = "sub dir", newDst= 2025/01/31 01:54:50 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2025/01/31 01:54:50 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hogigej4heme': Waiting for checks to finish 2025/01/31 01:54:50 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hogigej4heme': Waiting for transfers to finish 2025/01/31 01:54:53 INFO : sub dir/hello world: Copied (server-side copy) 2025/01/31 01:54:55 INFO : sub dir: Set directory modification time (using DirSetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-payebeb7toku'", Local "Local file system at /tmp/rclone695105756", Modify Window "1ms" 2025/01/31 01:54:56 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hogigej4heme': Purge remote 2025/01/31 01:54:58 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestServerSideCopy (13.55s) === RUN TestCopyOverSelf run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-payebeb7toku'", Local "Local file system at /tmp/rclone695105756", Modify Window "1ms" 2025/01/31 01:55:02 DEBUG : sub dir/hello world: md5 = d858754f12fdac5b4cbd9132b0cf5d08 OK 2025/01/31 01:55:03 DEBUG : Added delayed dir = "sub dir", newDst=sub dir 2025/01/31 01:55:03 DEBUG : sub dir/hello world: Sizes differ (src 17 vs dst 11) 2025/01/31 01:55:03 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-payebeb7toku': Waiting for checks to finish 2025/01/31 01:55:03 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-payebeb7toku': Waiting for transfers to finish 2025/01/31 01:55:04 DEBUG : sub dir/hello world: md5 = 0e76eba624912b568fbcfb952d8583fa OK 2025/01/31 01:55:04 INFO : sub dir/hello world: Copied (replaced existing) 2025/01/31 01:55:04 INFO : sub dir: Set directory modification time (using SetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-payebeb7toku'", Local "Local file system at /tmp/rclone695105756", Modify Window "1ms" 2025/01/31 01:55:06 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestCopyOverSelf (8.21s) === RUN TestServerSideCopyOverSelf run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-payebeb7toku'", Local "Local file system at /tmp/rclone695105756", Modify Window "1ms" 2025/01/31 01:55:10 DEBUG : sub dir/hello world: md5 = c5197fbf4ac645f37d2e12b474996635 OK 2025/01/31 01:55:10 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-sowezos9zuka" 2025/01/31 01:55:10 DEBUG : Creating backend with remote "TestDrive:crypt/9c3noj2v10drm8jprehl3e0obpopdgq941aguok3re9rvpq8s05g" sync_test.go:626: Server side copy (if possible) Encrypted drive 'TestCryptDrive:rclone-test-payebeb7toku' -> Encrypted drive 'TestCryptDrive:rclone-test-sowezos9zuka' 2025/01/31 01:55:12 DEBUG : Added delayed dir = "sub dir", newDst= 2025/01/31 01:55:12 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2025/01/31 01:55:12 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-sowezos9zuka': Waiting for checks to finish 2025/01/31 01:55:12 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-sowezos9zuka': Waiting for transfers to finish 2025/01/31 01:55:15 INFO : sub dir/hello world: Copied (server-side copy) 2025/01/31 01:55:15 INFO : sub dir: Set directory modification time (using DirSetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-payebeb7toku'", Local "Local file system at /tmp/rclone695105756", Modify Window "1ms" 2025/01/31 01:55:17 DEBUG : sub dir/hello world: md5 = a1629dd035cb1ad3f8b56ce32725c0ab OK 2025/01/31 01:55:18 DEBUG : sub dir: Directory modification time the same (differ by 0s, within tolerance 1ms) 2025/01/31 01:55:18 DEBUG : Added delayed dir = "sub dir", newDst=sub dir 2025/01/31 01:55:18 DEBUG : sub dir/hello world: Sizes differ (src 17 vs dst 11) 2025/01/31 01:55:18 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-sowezos9zuka': Waiting for checks to finish 2025/01/31 01:55:18 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-sowezos9zuka': Waiting for transfers to finish 2025/01/31 01:55:20 INFO : sub dir/hello world: Copied (server-side copy) 2025/01/31 01:55:21 INFO : sub dir: Set directory modification time (using SetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-payebeb7toku'", Local "Local file system at /tmp/rclone695105756", Modify Window "1ms" 2025/01/31 01:55:21 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-sowezos9zuka': Purge remote 2025/01/31 01:55:23 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestServerSideCopyOverSelf (17.60s) === RUN TestMoveOverSelf run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-payebeb7toku'", Local "Local file system at /tmp/rclone695105756", Modify Window "1ms" 2025/01/31 01:55:27 DEBUG : sub dir/hello world: md5 = 20f45496c99f586d4a56105689b03b2f OK 2025/01/31 01:55:28 DEBUG : Added delayed dir = "sub dir", newDst=sub dir 2025/01/31 01:55:28 DEBUG : sub dir/hello world: Sizes differ (src 17 vs dst 11) 2025/01/31 01:55:28 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-payebeb7toku': Waiting for checks to finish 2025/01/31 01:55:28 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-payebeb7toku': Waiting for transfers to finish 2025/01/31 01:55:30 DEBUG : sub dir/hello world: md5 = 73b7b637877786c81999edeacfe10a7e OK 2025/01/31 01:55:30 INFO : sub dir/hello world: Copied (replaced existing) 2025/01/31 01:55:30 INFO : sub dir/hello world: Deleted 2025/01/31 01:55:31 INFO : sub dir: Set directory modification time (using SetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-payebeb7toku'", Local "Local file system at /tmp/rclone695105756", Modify Window "1ms" 2025/01/31 01:55:32 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestMoveOverSelf (8.58s) === RUN TestServerSideMoveOverSelf run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-payebeb7toku'", Local "Local file system at /tmp/rclone695105756", Modify Window "1ms" 2025/01/31 01:55:36 DEBUG : sub dir/hello world: md5 = 67441c31d23abe290e60f5b9329c6d13 OK 2025/01/31 01:55:37 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-yihafew5teba" 2025/01/31 01:55:37 DEBUG : Config file has changed externally - reloading 2025/01/31 01:55:37 DEBUG : Creating backend with remote "TestDrive:crypt/uqugo3m9icio2c7tm8idvagaaksgrarbqg0vd2ckhbuj5a0g9740" sync_test.go:671: Server side copy (if possible) Encrypted drive 'TestCryptDrive:rclone-test-payebeb7toku' -> Encrypted drive 'TestCryptDrive:rclone-test-yihafew5teba' 2025/01/31 01:55:38 DEBUG : Added delayed dir = "sub dir", newDst= 2025/01/31 01:55:38 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2025/01/31 01:55:38 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yihafew5teba': Waiting for checks to finish 2025/01/31 01:55:38 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yihafew5teba': Waiting for transfers to finish 2025/01/31 01:55:41 INFO : sub dir/hello world: Copied (server-side copy) 2025/01/31 01:55:43 INFO : sub dir: Set directory modification time (using DirSetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-payebeb7toku'", Local "Local file system at /tmp/rclone695105756", Modify Window "1ms" 2025/01/31 01:55:45 DEBUG : sub dir/hello world: md5 = ef8bcf94fcf9036a2d3301bf9e3f6d0e OK 2025/01/31 01:55:46 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yihafew5teba': Using server-side directory move 2025/01/31 01:55:46 INFO : Encrypted drive 'TestCryptDrive:rclone-test-yihafew5teba': Server side directory move failed - fallback to file moves: can't copy directory - destination already exists 2025/01/31 01:55:46 DEBUG : sub dir: Directory modification time the same (differ by 0s, within tolerance 1ms) 2025/01/31 01:55:46 DEBUG : Added delayed dir = "sub dir", newDst=sub dir 2025/01/31 01:55:46 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yihafew5teba': Waiting for checks to finish 2025/01/31 01:55:46 DEBUG : sub dir/hello world: Sizes differ (src 17 vs dst 11) 2025/01/31 01:55:46 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yihafew5teba': Waiting for transfers to finish 2025/01/31 01:55:47 INFO : sub dir/hello world: Deleted 2025/01/31 01:55:48 INFO : sub dir/hello world: Moved (server-side) 2025/01/31 01:55:49 INFO : sub dir: Set directory modification time (using SetModTime) 2025/01/31 01:55:51 DEBUG : sub dir/hello world: md5 = fb5f0db7a34da9b178ec533780a6aea1 OK 2025/01/31 01:55:52 DEBUG : testing file moves 2025/01/31 01:55:52 DEBUG : sub dir: Directory modification time the same (differ by 0s, within tolerance 1ms) 2025/01/31 01:55:52 DEBUG : Added delayed dir = "sub dir", newDst=sub dir 2025/01/31 01:55:52 DEBUG : sub dir/hello world: Sizes differ (src 24 vs dst 17) 2025/01/31 01:55:52 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yihafew5teba': Waiting for checks to finish 2025/01/31 01:55:52 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yihafew5teba': Waiting for transfers to finish 2025/01/31 01:55:53 INFO : sub dir/hello world: Deleted 2025/01/31 01:55:54 INFO : sub dir/hello world: Moved (server-side) 2025/01/31 01:55:54 INFO : sub dir: Set directory modification time (using SetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-payebeb7toku'", Local "Local file system at /tmp/rclone695105756", Modify Window "1ms" 2025/01/31 01:55:55 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-yihafew5teba': Purge remote --- PASS: TestServerSideMoveOverSelf (24.59s) === RUN TestCopyAfterDelete run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-payebeb7toku'", Local "Local file system at /tmp/rclone695105756", Modify Window "1ms" 2025/01/31 01:56:01 DEBUG : sub dir/hello world: md5 = 359507c827009c8864126a111fe6ac1d OK 2025/01/31 01:56:01 ERROR : : error listing: directory not found 2025/01/31 01:56:01 INFO : Local file system at /tmp/rclone695105756: Making directory 2025/01/31 01:56:02 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-payebeb7toku': Waiting for checks to finish 2025/01/31 01:56:02 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-payebeb7toku': Waiting for transfers to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-payebeb7toku'", Local "Local file system at /tmp/rclone695105756", Modify Window "1ms" 2025/01/31 01:56:03 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestCopyAfterDelete (6.49s) === RUN TestCopyRedownload run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-payebeb7toku'", Local "Local file system at /tmp/rclone695105756", Modify Window "1ms" 2025/01/31 01:56:07 DEBUG : sub dir/hello world: md5 = 6db89c907200d6b3821f4b69943d5c47 OK 2025/01/31 01:56:08 DEBUG : Added delayed dir = "sub dir", newDst= 2025/01/31 01:56:08 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2025/01/31 01:56:08 DEBUG : Local file system at /tmp/rclone695105756: Waiting for checks to finish 2025/01/31 01:56:08 DEBUG : Local file system at /tmp/rclone695105756: Waiting for transfers to finish 2025/01/31 01:56:09 DEBUG : sub dir/hello world.285f0a30.partial: renamed to: sub dir/hello world 2025/01/31 01:56:09 INFO : sub dir/hello world: Copied (new) 2025/01/31 01:56:09 INFO : sub dir: Set directory modification time (using DirSetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-payebeb7toku'", Local "Local file system at /tmp/rclone695105756", Modify Window "1ms" 2025/01/31 01:56:10 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestCopyRedownload (6.77s) === RUN TestSyncBasedOnCheckSum run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-payebeb7toku'", Local "Local file system at /tmp/rclone695105756", Modify Window "1ms" 2025/01/31 01:56:12 DEBUG : check sum: Need to transfer - File not found at Destination 2025/01/31 01:56:12 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-payebeb7toku': Waiting for checks to finish 2025/01/31 01:56:12 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-payebeb7toku': Waiting for transfers to finish 2025/01/31 01:56:13 DEBUG : check sum: md5 = 10b4946dc8d1c94432184568b764bbd5 OK 2025/01/31 01:56:13 INFO : check sum: Copied (new) 2025/01/31 01:56:13 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-payebeb7toku'", Local "Local file system at /tmp/rclone695105756", Modify Window "1ms" 2025/01/31 01:56:14 NOTICE: Encrypted drive 'TestCryptDrive:rclone-test-payebeb7toku': --checksum is in use but the source and destination have no hashes in common; falling back to --size-only 2025/01/31 01:56:14 DEBUG : check sum: Size of src and dst objects identical 2025/01/31 01:56:14 DEBUG : check sum: Unchanged skipping 2025/01/31 01:56:14 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-payebeb7toku': Waiting for checks to finish 2025/01/31 01:56:14 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-payebeb7toku': Waiting for transfers to finish 2025/01/31 01:56:14 DEBUG : Waiting for deletions to finish 2025/01/31 01:56:14 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-payebeb7toku'", Local "Local file system at /tmp/rclone695105756", Modify Window "1ms" --- PASS: TestSyncBasedOnCheckSum (4.62s) === RUN TestSyncSizeOnly run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-payebeb7toku'", Local "Local file system at /tmp/rclone695105756", Modify Window "1ms" 2025/01/31 01:56:16 DEBUG : sizeonly: Need to transfer - File not found at Destination 2025/01/31 01:56:16 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-payebeb7toku': Waiting for checks to finish 2025/01/31 01:56:16 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-payebeb7toku': Waiting for transfers to finish 2025/01/31 01:56:18 DEBUG : sizeonly: md5 = 9f0061e8397a401499fd892b7a8791a2 OK 2025/01/31 01:56:18 INFO : sizeonly: Copied (new) 2025/01/31 01:56:18 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-payebeb7toku'", Local "Local file system at /tmp/rclone695105756", Modify Window "1ms" 2025/01/31 01:56:18 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-payebeb7toku': Waiting for checks to finish 2025/01/31 01:56:18 DEBUG : sizeonly: Sizes identical 2025/01/31 01:56:18 DEBUG : sizeonly: Unchanged skipping 2025/01/31 01:56:18 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-payebeb7toku': Waiting for transfers to finish 2025/01/31 01:56:18 DEBUG : Waiting for deletions to finish 2025/01/31 01:56:18 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-payebeb7toku'", Local "Local file system at /tmp/rclone695105756", Modify Window "1ms" --- PASS: TestSyncSizeOnly (4.46s) === RUN TestSyncIgnoreSize run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-payebeb7toku'", Local "Local file system at /tmp/rclone695105756", Modify Window "1ms" 2025/01/31 01:56:21 DEBUG : ignore-size: Need to transfer - File not found at Destination 2025/01/31 01:56:21 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-payebeb7toku': Waiting for checks to finish 2025/01/31 01:56:21 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-payebeb7toku': Waiting for transfers to finish 2025/01/31 01:56:22 DEBUG : ignore-size: md5 = f897ed454abfeefebefd76017403ef9b OK 2025/01/31 01:56:22 INFO : ignore-size: Copied (new) 2025/01/31 01:56:22 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-payebeb7toku'", Local "Local file system at /tmp/rclone695105756", Modify Window "1ms" 2025/01/31 01:56:23 DEBUG : ignore-size: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/01/31 01:56:23 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-payebeb7toku': Waiting for checks to finish 2025/01/31 01:56:23 DEBUG : ignore-size: Unchanged skipping 2025/01/31 01:56:23 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-payebeb7toku': Waiting for transfers to finish 2025/01/31 01:56:23 DEBUG : Waiting for deletions to finish 2025/01/31 01:56:23 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-payebeb7toku'", Local "Local file system at /tmp/rclone695105756", Modify Window "1ms" --- PASS: TestSyncIgnoreSize (4.66s) === RUN TestSyncIgnoreTimes run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-payebeb7toku'", Local "Local file system at /tmp/rclone695105756", Modify Window "1ms" 2025/01/31 01:56:27 DEBUG : existing: md5 = 2173b88836b21d4fd5125c83dd091711 OK 2025/01/31 01:56:27 DEBUG : existing: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/01/31 01:56:27 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-payebeb7toku': Waiting for checks to finish 2025/01/31 01:56:27 DEBUG : existing: Unchanged skipping 2025/01/31 01:56:27 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-payebeb7toku': Waiting for transfers to finish 2025/01/31 01:56:27 DEBUG : Waiting for deletions to finish 2025/01/31 01:56:27 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-payebeb7toku'", Local "Local file system at /tmp/rclone695105756", Modify Window "1ms" 2025/01/31 01:56:27 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-payebeb7toku': Waiting for checks to finish 2025/01/31 01:56:27 DEBUG : existing: Transferring unconditionally as --ignore-times is in use 2025/01/31 01:56:27 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-payebeb7toku': Waiting for transfers to finish 2025/01/31 01:56:29 DEBUG : existing: md5 = f0045590675349cb5d41c8fbc6c000ae OK 2025/01/31 01:56:29 INFO : existing: Copied (replaced existing) 2025/01/31 01:56:29 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-payebeb7toku'", Local "Local file system at /tmp/rclone695105756", Modify Window "1ms" --- PASS: TestSyncIgnoreTimes (5.84s) === RUN TestSyncIgnoreExisting run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-payebeb7toku'", Local "Local file system at /tmp/rclone695105756", Modify Window "1ms" 2025/01/31 01:56:31 DEBUG : existing: Need to transfer - File not found at Destination 2025/01/31 01:56:31 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-payebeb7toku': Waiting for checks to finish 2025/01/31 01:56:31 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-payebeb7toku': Waiting for transfers to finish 2025/01/31 01:56:33 DEBUG : existing: md5 = d133757166d0285f4556cc58834a12f6 OK 2025/01/31 01:56:33 INFO : existing: Copied (new) 2025/01/31 01:56:33 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-payebeb7toku'", Local "Local file system at /tmp/rclone695105756", Modify Window "1ms" 2025/01/31 01:56:33 DEBUG : existing: Destination exists, skipping 2025/01/31 01:56:33 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-payebeb7toku': Waiting for checks to finish 2025/01/31 01:56:33 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-payebeb7toku': Waiting for transfers to finish 2025/01/31 01:56:33 DEBUG : Waiting for deletions to finish 2025/01/31 01:56:33 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-payebeb7toku'", Local "Local file system at /tmp/rclone695105756", Modify Window "1ms" --- PASS: TestSyncIgnoreExisting (5.79s) === RUN TestSyncIgnoreErrors run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-payebeb7toku'", Local "Local file system at /tmp/rclone695105756", Modify Window "1ms" 2025/01/31 01:56:39 DEBUG : b/potato: md5 = 77307164577b1ab3fedca14629107e06 OK 2025/01/31 01:56:42 DEBUG : c/non empty space: md5 = d7a2fdceaf28b2e0784e0fcada293faa OK 2025/01/31 01:56:42 INFO : d: Making directory 2025/01/31 01:56:44 DEBUG : Added delayed dir = "a", newDst= 2025/01/31 01:56:44 DEBUG : Added delayed dir = "c", newDst=c 2025/01/31 01:56:44 DEBUG : c/non empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/01/31 01:56:44 DEBUG : a/potato2: Need to transfer - File not found at Destination 2025/01/31 01:56:44 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-payebeb7toku': Waiting for checks to finish 2025/01/31 01:56:44 DEBUG : c/non empty space: Unchanged skipping 2025/01/31 01:56:44 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-payebeb7toku': Waiting for transfers to finish 2025/01/31 01:56:46 DEBUG : a/potato2: md5 = 0214397aed150ae4eacd04b1df133e11 OK 2025/01/31 01:56:46 INFO : a/potato2: Copied (new) 2025/01/31 01:56:46 DEBUG : Waiting for deletions to finish 2025/01/31 01:56:47 INFO : b/potato: Deleted 2025/01/31 01:56:48 INFO : a: Set directory modification time (using DirSetModTime) 2025/01/31 01:56:48 INFO : d: Removing directory 2025/01/31 01:56:48 INFO : b: Removing directory 2025/01/31 01:56:49 DEBUG : 32d8ua6196mc1r7qkfog53rkg0: Rmdir: contains trashed file: "2m507n64kafsi59v9q71r281a4" 2025/01/31 01:56:49 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-payebeb7toku': deleted 2 directories run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-payebeb7toku'", Local "Local file system at /tmp/rclone695105756", Modify Window "1ms" 2025/01/31 01:56:51 DEBUG : 3i9du405pfogq3ncai6pg7ouio: Rmdir: contains trashed file: "982d3pss7t5pn0il16r2foj31s" 2025/01/31 01:56:52 DEBUG : 2bsvlrk2ne1lfitm6tttcu0qt8: Rmdir: contains trashed file: "89l8renevh3mji1c8r1p7qn6tg" --- PASS: TestSyncIgnoreErrors (17.10s) === RUN TestSyncAfterChangingModtimeOnly run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-payebeb7toku'", Local "Local file system at /tmp/rclone695105756", Modify Window "1ms" 2025/01/31 01:56:55 DEBUG : empty space: md5 = 9b2a675a943dce5341d9518a6f64a5dd OK 2025/01/31 01:56:56 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/31 01:56:56 NOTICE: empty space: Skipped copy as --dry-run is set (size 1) 2025/01/31 01:56:56 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-payebeb7toku': Waiting for checks to finish 2025/01/31 01:56:56 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-payebeb7toku': Waiting for transfers to finish 2025/01/31 01:56:56 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-payebeb7toku'", Local "Local file system at /tmp/rclone695105756", Modify Window "1ms" 2025/01/31 01:56:56 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-payebeb7toku': Waiting for checks to finish 2025/01/31 01:56:56 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/31 01:56:56 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-payebeb7toku': Waiting for transfers to finish 2025/01/31 01:56:57 DEBUG : empty space: md5 = 7d3e8613e73220163e728efe3670492c OK 2025/01/31 01:56:57 INFO : empty space: Copied (replaced existing) 2025/01/31 01:56:57 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-payebeb7toku'", Local "Local file system at /tmp/rclone695105756", Modify Window "1ms" --- PASS: TestSyncAfterChangingModtimeOnly (6.09s) === RUN TestSyncAfterChangingModtimeOnlyWithNoUpdateModTime run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-payebeb7toku'", Local "Local file system at /tmp/rclone695105756", Modify Window "1ms" sync_test.go:1016: Can't check this if no hashes supported --- PASS: TestSyncAfterChangingModtimeOnlyWithNoUpdateModTime (0.46s) === RUN TestSyncDoesntUpdateModtime run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-payebeb7toku'", Local "Local file system at /tmp/rclone695105756", Modify Window "1ms" 2025/01/31 01:57:02 DEBUG : foo: md5 = e0563742a796dfc50346377fbba07bb8 OK 2025/01/31 01:57:02 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/31 01:57:02 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-payebeb7toku': Waiting for checks to finish 2025/01/31 01:57:02 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-payebeb7toku': Waiting for transfers to finish 2025/01/31 01:57:04 DEBUG : foo: md5 = 23350d7974e17cacecd17f5a00a226ea OK 2025/01/31 01:57:04 INFO : foo: Copied (replaced existing) 2025/01/31 01:57:04 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-payebeb7toku'", Local "Local file system at /tmp/rclone695105756", Modify Window "1ms" --- PASS: TestSyncDoesntUpdateModtime (5.00s) === RUN TestSyncAfterAddingAFile run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-payebeb7toku'", Local "Local file system at /tmp/rclone695105756", Modify Window "1ms" 2025/01/31 01:57:07 DEBUG : empty space: md5 = c11a7f93a7ad15b8d5d86b6506e2dc76 OK 2025/01/31 01:57:07 DEBUG : potato: Need to transfer - File not found at Destination 2025/01/31 01:57:07 DEBUG : empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/01/31 01:57:07 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-payebeb7toku': Waiting for checks to finish 2025/01/31 01:57:07 DEBUG : empty space: Unchanged skipping 2025/01/31 01:57:07 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-payebeb7toku': Waiting for transfers to finish 2025/01/31 01:57:09 DEBUG : potato: md5 = 4b41a57b323ca172cbea7c4c215efefb OK 2025/01/31 01:57:09 INFO : potato: Copied (new) 2025/01/31 01:57:09 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-payebeb7toku'", Local "Local file system at /tmp/rclone695105756", Modify Window "1ms" --- PASS: TestSyncAfterAddingAFile (6.47s) === RUN TestSyncAfterChangingFilesSizeOnly run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-payebeb7toku'", Local "Local file system at /tmp/rclone695105756", Modify Window "1ms" 2025/01/31 01:57:13 DEBUG : potato: md5 = 8e4e9bc595ec61cf913c3ab3ba6a1c0d OK 2025/01/31 01:57:14 DEBUG : potato: Sizes differ (src 21 vs dst 60) 2025/01/31 01:57:14 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-payebeb7toku': Waiting for checks to finish 2025/01/31 01:57:14 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-payebeb7toku': Waiting for transfers to finish 2025/01/31 01:57:15 DEBUG : potato: md5 = 635e60cca34389f57d4dc08e679ae40f OK 2025/01/31 01:57:15 INFO : potato: Copied (replaced existing) 2025/01/31 01:57:15 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-payebeb7toku'", Local "Local file system at /tmp/rclone695105756", Modify Window "1ms" --- PASS: TestSyncAfterChangingFilesSizeOnly (5.00s) === RUN TestSyncAfterChangingContentsOnly run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-payebeb7toku'", Local "Local file system at /tmp/rclone695105756", Modify Window "1ms" 2025/01/31 01:57:18 DEBUG : potato: md5 = 71d58f2e04605c298237b01779ea84d4 OK 2025/01/31 01:57:19 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-payebeb7toku': Waiting for checks to finish 2025/01/31 01:57:19 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/31 01:57:19 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-payebeb7toku': Waiting for transfers to finish 2025/01/31 01:57:20 DEBUG : potato: md5 = c2df3e9cbff3fdc0483280a615ebbcdf OK 2025/01/31 01:57:20 INFO : potato: Copied (replaced existing) 2025/01/31 01:57:20 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-payebeb7toku'", Local "Local file system at /tmp/rclone695105756", Modify Window "1ms" --- PASS: TestSyncAfterChangingContentsOnly (5.00s) === RUN TestSyncAfterRemovingAFileAndAddingAFileDryRun run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-payebeb7toku'", Local "Local file system at /tmp/rclone695105756", Modify Window "1ms" 2025/01/31 01:57:23 DEBUG : potato: md5 = 3c8f4941bf2b04891f7b8b9a32c6ef5a OK 2025/01/31 01:57:25 DEBUG : empty space: md5 = 7ae89f1d55c3ff36877844b14d36dcde OK 2025/01/31 01:57:25 DEBUG : potato2: Need to transfer - File not found at Destination 2025/01/31 01:57:25 DEBUG : empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/01/31 01:57:25 DEBUG : empty space: Unchanged skipping 2025/01/31 01:57:25 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-payebeb7toku': Waiting for checks to finish 2025/01/31 01:57:25 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-payebeb7toku': Waiting for transfers to finish 2025/01/31 01:57:25 NOTICE: potato2: Skipped copy as --dry-run is set (size 60) 2025/01/31 01:57:25 DEBUG : Waiting for deletions to finish 2025/01/31 01:57:25 NOTICE: potato: Skipped delete as --dry-run is set (size 21) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-payebeb7toku'", Local "Local file system at /tmp/rclone695105756", Modify Window "1ms" --- PASS: TestSyncAfterRemovingAFileAndAddingAFileDryRun (5.89s) === RUN TestSyncAfterRemovingAFileAndAddingAFile run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-payebeb7toku'", Local "Local file system at /tmp/rclone695105756", Modify Window "1ms" 2025/01/31 01:57:29 DEBUG : potato: md5 = 1de655277b7b5f1a4e83709a41b01a5b OK 2025/01/31 01:57:31 DEBUG : empty space: md5 = b5a3c79c57f95712cc439431fb9cb275 OK 2025/01/31 01:57:31 DEBUG : potato2: Need to transfer - File not found at Destination 2025/01/31 01:57:31 DEBUG : empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/01/31 01:57:31 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-payebeb7toku': Waiting for checks to finish 2025/01/31 01:57:31 DEBUG : empty space: Unchanged skipping 2025/01/31 01:57:31 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-payebeb7toku': Waiting for transfers to finish 2025/01/31 01:57:33 DEBUG : potato2: md5 = 075fc2f2ca3ec7c13875055808383758 OK 2025/01/31 01:57:33 INFO : potato2: Copied (new) 2025/01/31 01:57:33 DEBUG : Waiting for deletions to finish 2025/01/31 01:57:34 INFO : potato: Deleted run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-payebeb7toku'", Local "Local file system at /tmp/rclone695105756", Modify Window "1ms" --- PASS: TestSyncAfterRemovingAFileAndAddingAFile (8.44s) === RUN TestSyncAfterRemovingAFileAndAddingAFileSubDir run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-payebeb7toku'", Local "Local file system at /tmp/rclone695105756", Modify Window "1ms" 2025/01/31 01:57:39 DEBUG : b/potato: md5 = f05f00a0adcd598f89c7f1d13d9a2827 OK 2025/01/31 01:57:41 DEBUG : c/non empty space: md5 = 27e7fa25b476dd81ac902524d0531338 OK 2025/01/31 01:57:41 INFO : d: Making directory 2025/01/31 01:57:42 INFO : d/e: Making directory 2025/01/31 01:57:45 DEBUG : Added delayed dir = "a", newDst= 2025/01/31 01:57:45 DEBUG : Added delayed dir = "c", newDst=c 2025/01/31 01:57:45 DEBUG : a/potato2: Need to transfer - File not found at Destination 2025/01/31 01:57:45 DEBUG : c/non empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/01/31 01:57:45 DEBUG : c/non empty space: Unchanged skipping 2025/01/31 01:57:45 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-payebeb7toku': Waiting for checks to finish 2025/01/31 01:57:45 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-payebeb7toku': Waiting for transfers to finish 2025/01/31 01:57:47 DEBUG : a/potato2: md5 = 8b8cf4deffa03812ab772846edeb55f1 OK 2025/01/31 01:57:47 INFO : a/potato2: Copied (new) 2025/01/31 01:57:47 DEBUG : Waiting for deletions to finish 2025/01/31 01:57:48 INFO : b/potato: Deleted 2025/01/31 01:57:48 INFO : a: Set directory modification time (using DirSetModTime) 2025/01/31 01:57:48 INFO : d/e: Removing directory 2025/01/31 01:57:49 INFO : d: Removing directory 2025/01/31 01:57:49 DEBUG : ka6id8d20d3s5ktapedlphgta8: Rmdir: contains trashed file: "r8sppajuabeak3sbgj2ak8vuf8" 2025/01/31 01:57:50 INFO : b: Removing directory 2025/01/31 01:57:50 DEBUG : 32d8ua6196mc1r7qkfog53rkg0: Rmdir: contains trashed file: "2m507n64kafsi59v9q71r281a4" 2025/01/31 01:57:51 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-payebeb7toku': deleted 3 directories run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-payebeb7toku'", Local "Local file system at /tmp/rclone695105756", Modify Window "1ms" 2025/01/31 01:57:53 DEBUG : 3i9du405pfogq3ncai6pg7ouio: Rmdir: contains trashed file: "982d3pss7t5pn0il16r2foj31s" 2025/01/31 01:57:54 DEBUG : 2bsvlrk2ne1lfitm6tttcu0qt8: Rmdir: contains trashed file: "89l8renevh3mji1c8r1p7qn6tg" --- PASS: TestSyncAfterRemovingAFileAndAddingAFileSubDir (19.38s) === RUN TestSyncAfterRemovingAFileAndAddingAFileSubDirWithErrors run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-payebeb7toku'", Local "Local file system at /tmp/rclone695105756", Modify Window "1ms" 2025/01/31 01:57:58 DEBUG : b/potato: md5 = 32d3b8d074b863e6d32f69f02b4032c9 OK 2025/01/31 01:58:00 DEBUG : c/non empty space: md5 = 26935658994c9969705f59403d218257 OK 2025/01/31 01:58:00 INFO : d: Making directory 2025/01/31 01:58:02 DEBUG : Added delayed dir = "a", newDst= 2025/01/31 01:58:02 DEBUG : Added delayed dir = "c", newDst=c 2025/01/31 01:58:02 DEBUG : c/non empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/01/31 01:58:02 DEBUG : a/potato2: Need to transfer - File not found at Destination 2025/01/31 01:58:02 DEBUG : c/non empty space: Unchanged skipping 2025/01/31 01:58:02 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-payebeb7toku': Waiting for checks to finish 2025/01/31 01:58:02 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-payebeb7toku': Waiting for transfers to finish 2025/01/31 01:58:05 DEBUG : a/potato2: md5 = e12aaae0b54df25bb90c87a423ebffa2 OK 2025/01/31 01:58:05 INFO : a/potato2: Copied (new) 2025/01/31 01:58:05 ERROR : Encrypted drive 'TestCryptDrive:rclone-test-payebeb7toku': not deleting files as there were IO errors 2025/01/31 01:58:05 INFO : a: Set directory modification time (using DirSetModTime) 2025/01/31 01:58:05 ERROR : Encrypted drive 'TestCryptDrive:rclone-test-payebeb7toku': not deleting directories as there were IO errors run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-payebeb7toku'", Local "Local file system at /tmp/rclone695105756", Modify Window "1ms" 2025/01/31 01:58:09 DEBUG : 3i9du405pfogq3ncai6pg7ouio: Rmdir: contains trashed file: "982d3pss7t5pn0il16r2foj31s" 2025/01/31 01:58:10 DEBUG : 32d8ua6196mc1r7qkfog53rkg0: Rmdir: contains trashed file: "2m507n64kafsi59v9q71r281a4" 2025/01/31 01:58:11 DEBUG : 2bsvlrk2ne1lfitm6tttcu0qt8: Rmdir: contains trashed file: "89l8renevh3mji1c8r1p7qn6tg" --- PASS: TestSyncAfterRemovingAFileAndAddingAFileSubDirWithErrors (16.55s) === RUN TestSyncDeleteAfter --- PASS: TestSyncDeleteAfter (0.00s) === RUN TestSyncDeleteDuring run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-payebeb7toku'", Local "Local file system at /tmp/rclone695105756", Modify Window "1ms" 2025/01/31 01:58:14 DEBUG : potato: md5 = 1e92c91d60786cce29b06e6273f9800a OK 2025/01/31 01:58:15 DEBUG : empty space: md5 = 224f031eccdeda2bd260f40106f61947 OK 2025/01/31 01:58:15 DEBUG : Waiting for deletions to finish 2025/01/31 01:58:16 DEBUG : potato2: Need to transfer - File not found at Destination 2025/01/31 01:58:16 DEBUG : empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/01/31 01:58:16 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-payebeb7toku': Waiting for checks to finish 2025/01/31 01:58:16 DEBUG : empty space: Unchanged skipping 2025/01/31 01:58:16 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-payebeb7toku': Waiting for transfers to finish 2025/01/31 01:58:16 INFO : potato: Deleted 2025/01/31 01:58:17 DEBUG : potato2: md5 = 4f75947f6c3c2a2a16621728e9fdb5f6 OK 2025/01/31 01:58:17 INFO : potato2: Copied (new) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-payebeb7toku'", Local "Local file system at /tmp/rclone695105756", Modify Window "1ms" --- PASS: TestSyncDeleteDuring (8.46s) === RUN TestSyncDeleteBefore run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-payebeb7toku'", Local "Local file system at /tmp/rclone695105756", Modify Window "1ms" 2025/01/31 01:58:22 DEBUG : potato: md5 = b0db5aa2d42a53ac066b8ce9680a278d OK 2025/01/31 01:58:24 DEBUG : empty space: md5 = df25ba2d0b4d7f48bc5644ea262c7c37 OK 2025/01/31 01:58:24 DEBUG : Waiting for deletions to finish 2025/01/31 01:58:24 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-payebeb7toku': Waiting for checks to finish 2025/01/31 01:58:24 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-payebeb7toku': Waiting for transfers to finish 2025/01/31 01:58:25 INFO : potato: Deleted 2025/01/31 01:58:25 DEBUG : potato2: Need to transfer - File not found at Destination 2025/01/31 01:58:25 DEBUG : empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/01/31 01:58:25 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-payebeb7toku': Waiting for checks to finish 2025/01/31 01:58:25 DEBUG : empty space: Unchanged skipping 2025/01/31 01:58:25 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-payebeb7toku': Waiting for transfers to finish 2025/01/31 01:58:27 DEBUG : potato2: md5 = a772a868c849aec1da386ec432fc97cc OK 2025/01/31 01:58:27 INFO : potato2: Copied (new) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-payebeb7toku'", Local "Local file system at /tmp/rclone695105756", Modify Window "1ms" --- PASS: TestSyncDeleteBefore (8.45s) === RUN TestCopyDeleteBefore run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-payebeb7toku'", Local "Local file system at /tmp/rclone695105756", Modify Window "1ms" 2025/01/31 01:58:30 DEBUG : potato: md5 = d28902edb7696d941c634718b60307d3 OK 2025/01/31 01:58:31 DEBUG : potato2: Need to transfer - File not found at Destination 2025/01/31 01:58:31 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-payebeb7toku': Waiting for checks to finish 2025/01/31 01:58:31 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-payebeb7toku': Waiting for transfers to finish 2025/01/31 01:58:33 DEBUG : potato2: md5 = 3b4bce27d7a6ba8598abd381ffb50e5d OK 2025/01/31 01:58:33 INFO : potato2: Copied (new) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-payebeb7toku'", Local "Local file system at /tmp/rclone695105756", Modify Window "1ms" --- PASS: TestCopyDeleteBefore (6.85s) === RUN TestSyncWithExclude run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-payebeb7toku'", Local "Local file system at /tmp/rclone695105756", Modify Window "1ms" 2025/01/31 01:58:37 DEBUG : potato2: md5 = f59086b0a4ce11aa7294246298208b2e OK 2025/01/31 01:58:39 DEBUG : empty space: md5 = 605cc565cb0c5dcc7bdc0a32d6a896f8 OK 2025/01/31 01:58:39 DEBUG : enormous: Excluded (Size Filter) 2025/01/31 01:58:39 DEBUG : enormous: Excluded 2025/01/31 01:58:39 DEBUG : potato2: Excluded (Size Filter) 2025/01/31 01:58:39 DEBUG : potato2: Excluded 2025/01/31 01:58:39 DEBUG : potato2: Excluded (Size Filter) 2025/01/31 01:58:39 DEBUG : empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/01/31 01:58:39 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-payebeb7toku': Waiting for checks to finish 2025/01/31 01:58:39 DEBUG : empty space: Unchanged skipping 2025/01/31 01:58:39 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-payebeb7toku': Waiting for transfers to finish 2025/01/31 01:58:39 DEBUG : Waiting for deletions to finish 2025/01/31 01:58:39 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-payebeb7toku'", Local "Local file system at /tmp/rclone695105756", Modify Window "1ms" 2025/01/31 01:58:40 DEBUG : enormous: Excluded (Size Filter) 2025/01/31 01:58:40 DEBUG : enormous: Excluded 2025/01/31 01:58:40 DEBUG : potato2: Excluded (Size Filter) 2025/01/31 01:58:40 DEBUG : potato2: Excluded 2025/01/31 01:58:40 DEBUG : potato2: Excluded (Size Filter) 2025/01/31 01:58:40 DEBUG : empty space: Size and modification time the same (differ by 456.789µs, within tolerance 1ms) 2025/01/31 01:58:40 DEBUG : Local file system at /tmp/rclone695105756: Waiting for checks to finish 2025/01/31 01:58:40 DEBUG : empty space: Unchanged skipping 2025/01/31 01:58:40 DEBUG : Local file system at /tmp/rclone695105756: Waiting for transfers to finish 2025/01/31 01:58:40 DEBUG : Waiting for deletions to finish 2025/01/31 01:58:40 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-payebeb7toku'", Local "Local file system at /tmp/rclone695105756", Modify Window "1ms" --- PASS: TestSyncWithExclude (6.55s) === RUN TestSyncWithExcludeAndDeleteExcluded run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-payebeb7toku'", Local "Local file system at /tmp/rclone695105756", Modify Window "1ms" 2025/01/31 01:58:44 DEBUG : potato2: md5 = 9f183babc3d3f04cd788b1a7a047d87b OK 2025/01/31 01:58:45 DEBUG : empty space: md5 = 41aa8bdae1c21ac05b18e7711780e2b2 OK 2025/01/31 01:58:47 DEBUG : enormous: md5 = 0e8407b2456d643be7136cf2fac51c44 OK 2025/01/31 01:58:47 DEBUG : enormous: Excluded (Size Filter) 2025/01/31 01:58:47 DEBUG : enormous: Excluded 2025/01/31 01:58:47 DEBUG : potato2: Excluded (Size Filter) 2025/01/31 01:58:47 DEBUG : potato2: Excluded 2025/01/31 01:58:47 DEBUG : empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/01/31 01:58:47 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-payebeb7toku': Waiting for checks to finish 2025/01/31 01:58:47 DEBUG : empty space: Unchanged skipping 2025/01/31 01:58:47 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-payebeb7toku': Waiting for transfers to finish 2025/01/31 01:58:47 DEBUG : Waiting for deletions to finish 2025/01/31 01:58:48 INFO : potato2: Deleted 2025/01/31 01:58:48 INFO : enormous: Deleted 2025/01/31 01:58:48 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-payebeb7toku'", Local "Local file system at /tmp/rclone695105756", Modify Window "1ms" 2025/01/31 01:58:48 DEBUG : empty space: Size and modification time the same (differ by 456.789µs, within tolerance 1ms) 2025/01/31 01:58:48 DEBUG : empty space: Unchanged skipping 2025/01/31 01:58:48 DEBUG : Local file system at /tmp/rclone695105756: Waiting for checks to finish 2025/01/31 01:58:48 DEBUG : Local file system at /tmp/rclone695105756: Waiting for transfers to finish 2025/01/31 01:58:48 DEBUG : Waiting for deletions to finish 2025/01/31 01:58:48 INFO : enormous: Deleted 2025/01/31 01:58:48 INFO : potato2: Deleted 2025/01/31 01:58:48 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-payebeb7toku'", Local "Local file system at /tmp/rclone695105756", Modify Window "1ms" --- PASS: TestSyncWithExcludeAndDeleteExcluded (8.08s) === RUN TestSyncWithUpdateOlder run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-payebeb7toku'", Local "Local file system at /tmp/rclone695105756", Modify Window "1ms" 2025/01/31 01:58:52 DEBUG : one: md5 = c8aa1141da89acfda6dfa51c3ed21ac1 OK 2025/01/31 01:58:54 DEBUG : two: md5 = 329137921c1c03ad32fb8836dc606093 OK 2025/01/31 01:58:55 DEBUG : three: md5 = 6661c543e492796bf6524158598c4ff7 OK 2025/01/31 01:58:57 DEBUG : four: md5 = 0226c0b965721b61a10b97f36e41d612 OK 2025/01/31 01:58:57 DEBUG : five: Need to transfer - File not found at Destination 2025/01/31 01:58:57 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-payebeb7toku': Waiting for checks to finish 2025/01/31 01:58:57 DEBUG : four: Sizes differ (src 4 vs dst 8) 2025/01/31 01:58:57 DEBUG : three: Sizes identical 2025/01/31 01:58:57 DEBUG : one: Destination is newer than source, skipping 2025/01/31 01:58:57 DEBUG : four: Destination mod time is within 1s of source but files differ, transferring 2025/01/31 01:58:57 DEBUG : three: Destination mod time is within 1s of source and files identical, skipping 2025/01/31 01:58:57 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-payebeb7toku': Waiting for transfers to finish 2025/01/31 01:58:58 DEBUG : four: md5 = 5e2cb2c4caedc68f2ebf182b97fef66c OK 2025/01/31 01:58:58 INFO : four: Copied (replaced existing) 2025/01/31 01:58:59 DEBUG : two: md5 = 852cca68d8ffe0351d315da8deb1b6cf OK 2025/01/31 01:58:59 INFO : two: Copied (replaced existing) 2025/01/31 01:58:59 DEBUG : five: md5 = 17742060239fba7d15fa4df796504667 OK 2025/01/31 01:58:59 INFO : five: Copied (new) 2025/01/31 01:58:59 DEBUG : Waiting for deletions to finish sync_test.go:1449: Skip test with --checksum as no hashes supported --- PASS: TestSyncWithUpdateOlder (12.03s) === 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-payebeb7toku'", Local "Local file system at /tmp/rclone695105756", Modify Window "1ms" sync_test.go:1538: Can track renames: false 2025/01/31 01:59:02 ERROR : Encrypted drive 'TestCryptDrive:rclone-test-payebeb7toku': Ignoring --track-renames as the source and destination do not have a common hash 2025/01/31 01:59:03 DEBUG : potato: Need to transfer - File not found at Destination 2025/01/31 01:59:03 DEBUG : yam: Need to transfer - File not found at Destination 2025/01/31 01:59:03 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-payebeb7toku': Waiting for checks to finish 2025/01/31 01:59:03 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-payebeb7toku': Waiting for transfers to finish 2025/01/31 01:59:04 DEBUG : yam: md5 = 9c7238b0605dda6698d9fd7532171e7d OK 2025/01/31 01:59:04 INFO : yam: Copied (new) 2025/01/31 01:59:04 DEBUG : potato: md5 = bc55ef5f04071c5293838a0fee045cd3 OK 2025/01/31 01:59:04 INFO : potato: Copied (new) 2025/01/31 01:59:04 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-payebeb7toku'", Local "Local file system at /tmp/rclone695105756", Modify Window "1ms" 2025/01/31 01:59:04 ERROR : Encrypted drive 'TestCryptDrive:rclone-test-payebeb7toku': Ignoring --track-renames as the source and destination do not have a common hash 2025/01/31 01:59:05 DEBUG : yaml: Need to transfer - File not found at Destination 2025/01/31 01:59:05 DEBUG : potato: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/01/31 01:59:05 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-payebeb7toku': Waiting for checks to finish 2025/01/31 01:59:05 DEBUG : potato: Unchanged skipping 2025/01/31 01:59:05 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-payebeb7toku': Waiting for transfers to finish 2025/01/31 01:59:06 DEBUG : yaml: md5 = 0cff536826278a7f43d4ccc1147075d1 OK 2025/01/31 01:59:06 INFO : yaml: Copied (new) 2025/01/31 01:59:06 DEBUG : Waiting for deletions to finish 2025/01/31 01:59:07 INFO : yam: Deleted run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-payebeb7toku'", Local "Local file system at /tmp/rclone695105756", Modify Window "1ms" --- PASS: TestSyncWithTrackRenames (7.99s) === RUN TestParseRenamesStrategyModtime --- PASS: TestParseRenamesStrategyModtime (0.00s) === RUN TestRenamesStrategyModtime --- PASS: TestRenamesStrategyModtime (0.00s) === RUN TestSyncWithTrackRenamesStrategyModtime run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-payebeb7toku'", Local "Local file system at /tmp/rclone695105756", Modify Window "1ms" sync_test.go:1610: Can track renames: true 2025/01/31 01:59:11 INFO : Encrypted drive 'TestCryptDrive:rclone-test-payebeb7toku': Making map for --track-renames 2025/01/31 01:59:11 INFO : Encrypted drive 'TestCryptDrive:rclone-test-payebeb7toku': Finished making map for --track-renames 2025/01/31 01:59:11 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-payebeb7toku': Waiting for checks to finish 2025/01/31 01:59:11 DEBUG : potato: Need to transfer - No matching file found at Destination 2025/01/31 01:59:11 DEBUG : yam: Need to transfer - No matching file found at Destination 2025/01/31 01:59:11 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-payebeb7toku': Waiting for renames to finish 2025/01/31 01:59:11 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-payebeb7toku': Waiting for transfers to finish 2025/01/31 01:59:12 DEBUG : potato: md5 = a1aa28c79dd1320d3f1ab4aa87a7f21c OK 2025/01/31 01:59:12 INFO : potato: Copied (new) 2025/01/31 01:59:12 DEBUG : yam: md5 = 39b24f5db5b68f488bad06eed8efac92 OK 2025/01/31 01:59:12 INFO : yam: Copied (new) 2025/01/31 01:59:12 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-payebeb7toku'", Local "Local file system at /tmp/rclone695105756", Modify Window "1ms" 2025/01/31 01:59:13 DEBUG : potato: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/01/31 01:59:13 INFO : Encrypted drive 'TestCryptDrive:rclone-test-payebeb7toku': Making map for --track-renames 2025/01/31 01:59:13 INFO : Encrypted drive 'TestCryptDrive:rclone-test-payebeb7toku': Finished making map for --track-renames 2025/01/31 01:59:13 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-payebeb7toku': Waiting for checks to finish 2025/01/31 01:59:13 DEBUG : potato: Unchanged skipping 2025/01/31 01:59:13 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-payebeb7toku': Waiting for renames to finish 2025/01/31 01:59:14 INFO : yam: Moved (server-side) to: yaml 2025/01/31 01:59:14 INFO : yaml: Renamed from "yam" 2025/01/31 01:59:14 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-payebeb7toku': Waiting for transfers to finish 2025/01/31 01:59:14 DEBUG : Waiting for deletions to finish 2025/01/31 01:59:14 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-payebeb7toku'", Local "Local file system at /tmp/rclone695105756", Modify Window "1ms" --- PASS: TestSyncWithTrackRenamesStrategyModtime (5.96s) === RUN TestSyncWithTrackRenamesStrategyLeaf run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-payebeb7toku'", Local "Local file system at /tmp/rclone695105756", Modify Window "1ms" sync_test.go:1649: Can track renames: true 2025/01/31 01:59:17 DEBUG : Added delayed dir = "sub", newDst= 2025/01/31 01:59:17 INFO : Encrypted drive 'TestCryptDrive:rclone-test-payebeb7toku': Making map for --track-renames 2025/01/31 01:59:17 INFO : Encrypted drive 'TestCryptDrive:rclone-test-payebeb7toku': Finished making map for --track-renames 2025/01/31 01:59:17 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-payebeb7toku': Waiting for checks to finish 2025/01/31 01:59:17 DEBUG : potato: Need to transfer - No matching file found at Destination 2025/01/31 01:59:17 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-payebeb7toku': Waiting for renames to finish 2025/01/31 01:59:17 DEBUG : sub/yam: Need to transfer - No matching file found at Destination 2025/01/31 01:59:17 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-payebeb7toku': Waiting for transfers to finish 2025/01/31 01:59:19 DEBUG : potato: md5 = 1653ccde8fe1f18d1097b8571d14f126 OK 2025/01/31 01:59:19 INFO : potato: Copied (new) 2025/01/31 01:59:19 DEBUG : sub/yam: md5 = f2ba72ee0c03258a1835ac19add91188 OK 2025/01/31 01:59:19 INFO : sub/yam: Copied (new) 2025/01/31 01:59:19 DEBUG : Waiting for deletions to finish 2025/01/31 01:59:20 INFO : sub: Set directory modification time (using DirSetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-payebeb7toku'", Local "Local file system at /tmp/rclone695105756", Modify Window "1ms" 2025/01/31 01:59:21 DEBUG : Added delayed dir = "sub", newDst=sub 2025/01/31 01:59:21 DEBUG : potato: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/01/31 01:59:21 DEBUG : potato: Unchanged skipping 2025/01/31 01:59:21 INFO : Encrypted drive 'TestCryptDrive:rclone-test-payebeb7toku': Making map for --track-renames 2025/01/31 01:59:21 INFO : Encrypted drive 'TestCryptDrive:rclone-test-payebeb7toku': Finished making map for --track-renames 2025/01/31 01:59:21 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-payebeb7toku': Waiting for checks to finish 2025/01/31 01:59:21 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-payebeb7toku': Waiting for renames to finish 2025/01/31 01:59:22 INFO : sub/yam: Moved (server-side) to: yam 2025/01/31 01:59:22 INFO : yam: Renamed from "sub/yam" 2025/01/31 01:59:22 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-payebeb7toku': Waiting for transfers to finish 2025/01/31 01:59:22 DEBUG : Waiting for deletions to finish 2025/01/31 01:59:22 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-payebeb7toku'", Local "Local file system at /tmp/rclone695105756", Modify Window "1ms" --- PASS: TestSyncWithTrackRenamesStrategyLeaf (9.90s) === RUN TestServerSideMoveLocal run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-payebeb7toku'", Local "Local file system at /tmp/rclone695105756", Modify Window "1ms" 2025/01/31 01:59:26 DEBUG : Creating backend with remote "/tmp/rclone695105756/dir1" 2025/01/31 01:59:26 DEBUG : Config file has changed externally - reloading 2025/01/31 01:59:26 DEBUG : Creating backend with remote "/tmp/rclone695105756/dir2" 2025/01/31 01:59:26 DEBUG : Local file system at /tmp/rclone695105756/dir2: Using server-side directory move 2025/01/31 01:59:26 INFO : Local file system at /tmp/rclone695105756/dir2: Server side directory move failed - fallback to file moves: can't copy directory - destination already exists 2025/01/31 01:59:26 DEBUG : file1.txt: Need to transfer - File not found at Destination 2025/01/31 01:59:26 INFO : file1.txt: Moved (server-side) 2025/01/31 01:59:26 DEBUG : Local file system at /tmp/rclone695105756/dir2: Waiting for checks to finish 2025/01/31 01:59:26 DEBUG : Local file system at /tmp/rclone695105756/dir2: Waiting for transfers to finish --- PASS: TestServerSideMoveLocal (0.46s) === RUN TestMoveWithDeleteEmptySrcDirs run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-payebeb7toku'", Local "Local file system at /tmp/rclone695105756", Modify Window "1ms" 2025/01/31 01:59:27 DEBUG : Added delayed dir = "nested", newDst= 2025/01/31 01:59:27 DEBUG : Added delayed dir = "sub dir", newDst= 2025/01/31 01:59:27 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2025/01/31 01:59:27 DEBUG : Added delayed dir = "nested/sub dir", newDst= 2025/01/31 01:59:27 DEBUG : nested/sub dir/file: Need to transfer - File not found at Destination 2025/01/31 01:59:27 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-payebeb7toku': Waiting for checks to finish 2025/01/31 01:59:27 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-payebeb7toku': Waiting for transfers to finish 2025/01/31 01:59:29 DEBUG : sub dir/hello world: md5 = b3ee766cd856959c3a767fe662749892 OK 2025/01/31 01:59:29 INFO : sub dir/hello world: Copied (new) 2025/01/31 01:59:29 INFO : sub dir/hello world: Deleted 2025/01/31 01:59:32 DEBUG : nested/sub dir/file: md5 = 85607a0b8c949416fab339b604e363cf OK 2025/01/31 01:59:32 INFO : nested/sub dir/file: Copied (new) 2025/01/31 01:59:32 INFO : nested/sub dir/file: Deleted 2025/01/31 01:59:32 INFO : nested/sub dir: Set directory modification time (using DirSetModTime) 2025/01/31 01:59:33 INFO : nested: Set directory modification time (using DirSetModTime) 2025/01/31 01:59:33 INFO : sub dir: Set directory modification time (using DirSetModTime) 2025/01/31 01:59:33 INFO : sub dir: Removing directory 2025/01/31 01:59:33 INFO : nested/sub dir: Removing directory 2025/01/31 01:59:33 INFO : nested: Removing directory 2025/01/31 01:59:33 DEBUG : Local file system at /tmp/rclone695105756: deleted 3 directories run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-payebeb7toku'", Local "Local file system at /tmp/rclone695105756", Modify Window "1ms" 2025/01/31 01:59:36 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" 2025/01/31 01:59:36 DEBUG : 37qp6d1gohacv723ij3brofbu8/14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "ftp4kuv8se7tqduu6pmmcvjsmk" 2025/01/31 01:59:37 DEBUG : 37qp6d1gohacv723ij3brofbu8: Rmdir: contains trashed file: "14begaa36ih249fgrnfk6nulg0" --- PASS: TestMoveWithDeleteEmptySrcDirs (11.95s) === RUN TestMoveWithoutDeleteEmptySrcDirs run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-payebeb7toku'", Local "Local file system at /tmp/rclone695105756", Modify Window "1ms" 2025/01/31 01:59:39 DEBUG : Added delayed dir = "nested", newDst= 2025/01/31 01:59:39 DEBUG : Added delayed dir = "sub dir", newDst= 2025/01/31 01:59:39 DEBUG : sub dir/hello world: Need to transfer - File not found at Destination 2025/01/31 01:59:39 DEBUG : Added delayed dir = "nested/sub dir", newDst= 2025/01/31 01:59:39 DEBUG : nested/sub dir/file: Need to transfer - File not found at Destination 2025/01/31 01:59:39 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-payebeb7toku': Waiting for checks to finish 2025/01/31 01:59:39 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-payebeb7toku': Waiting for transfers to finish 2025/01/31 01:59:41 DEBUG : sub dir/hello world: md5 = e17210381a03bc48b1f3b503da6710ba OK 2025/01/31 01:59:41 INFO : sub dir/hello world: Copied (new) 2025/01/31 01:59:41 INFO : sub dir/hello world: Deleted 2025/01/31 01:59:44 DEBUG : nested/sub dir/file: md5 = a44e1aae4bff9a6e02347fe552e4aa63 OK 2025/01/31 01:59:44 INFO : nested/sub dir/file: Copied (new) 2025/01/31 01:59:44 INFO : nested/sub dir/file: Deleted 2025/01/31 01:59:44 INFO : nested/sub dir: Set directory modification time (using DirSetModTime) 2025/01/31 01:59:45 INFO : sub dir: Set directory modification time (using DirSetModTime) 2025/01/31 01:59:45 INFO : nested: Set directory modification time (using DirSetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-payebeb7toku'", Local "Local file system at /tmp/rclone695105756", Modify Window "1ms" 2025/01/31 01:59:48 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" 2025/01/31 01:59:49 DEBUG : 37qp6d1gohacv723ij3brofbu8/14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "ftp4kuv8se7tqduu6pmmcvjsmk" 2025/01/31 01:59:50 DEBUG : 37qp6d1gohacv723ij3brofbu8: Rmdir: contains trashed file: "14begaa36ih249fgrnfk6nulg0" --- PASS: TestMoveWithoutDeleteEmptySrcDirs (12.43s) === RUN TestMoveWithIgnoreExisting run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-payebeb7toku'", Local "Local file system at /tmp/rclone695105756", Modify Window "1ms" 2025/01/31 01:59:51 DEBUG : existing: Need to transfer - File not found at Destination 2025/01/31 01:59:51 DEBUG : existing-b: Need to transfer - File not found at Destination 2025/01/31 01:59:51 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-payebeb7toku': Waiting for checks to finish 2025/01/31 01:59:51 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-payebeb7toku': Waiting for transfers to finish 2025/01/31 01:59:53 DEBUG : existing-b: md5 = 959fa33768d797b8bcd8c385c8226dce OK 2025/01/31 01:59:53 INFO : existing-b: Copied (new) 2025/01/31 01:59:53 INFO : existing-b: Deleted 2025/01/31 01:59:53 DEBUG : existing: md5 = 68b17a02a690618b2c5e3a284c34e00e OK 2025/01/31 01:59:53 INFO : existing: Copied (new) 2025/01/31 01:59:53 INFO : existing: Deleted 2025/01/31 01:59:53 DEBUG : existing: Destination exists, skipping 2025/01/31 01:59:53 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-payebeb7toku': Waiting for checks to finish 2025/01/31 01:59:53 DEBUG : existing: Not removing source file as destination file exists and --ignore-existing is set 2025/01/31 01:59:53 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-payebeb7toku': Waiting for transfers to finish 2025/01/31 01:59:53 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-payebeb7toku'", Local "Local file system at /tmp/rclone695105756", Modify Window "1ms" --- PASS: TestMoveWithIgnoreExisting (4.38s) === RUN TestServerSideMove run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-payebeb7toku'", Local "Local file system at /tmp/rclone695105756", Modify Window "1ms" 2025/01/31 01:59:56 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-heponev5kige" 2025/01/31 01:59:56 DEBUG : Config file has changed externally - reloading 2025/01/31 01:59:56 DEBUG : Creating backend with remote "TestDrive:crypt/bsvn7vs5jg2seinrn7l3buj9d0426c82vcc295s0mpbcsdcua5gg" 2025/01/31 01:59:58 DEBUG : potato2: md5 = 9e203e4867172e8b92f96b5734a2ef2e OK 2025/01/31 02:00:00 DEBUG : empty space: md5 = 16f4577c78be54ed4f6f1162bbbe941c OK 2025/01/31 02:00:01 DEBUG : potato3: md5 = 776cf51aeb7f162b0c3c437092560141 OK sync_test.go:1705: Server side move (if possible) Encrypted drive 'TestCryptDrive:rclone-test-payebeb7toku' -> Encrypted drive 'TestCryptDrive:rclone-test-heponev5kige' 2025/01/31 02:00:04 DEBUG : empty space: md5 = d4cd27a45bd2a923eca6601d63984345 OK 2025/01/31 02:00:05 DEBUG : potato3: md5 = 56a099b1d9c06ae2a88af74efb5aaf35 OK 2025/01/31 02:00:06 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-heponev5kige': Using server-side directory move 2025/01/31 02:00:06 INFO : Encrypted drive 'TestCryptDrive:rclone-test-heponev5kige': Server side directory move failed - fallback to file moves: can't copy directory - destination already exists 2025/01/31 02:00:06 DEBUG : potato2: Need to transfer - File not found at Destination 2025/01/31 02:00:06 DEBUG : empty space: Size and modification time the same (differ by 0s, within tolerance 1ms) 2025/01/31 02:00:06 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-heponev5kige': Waiting for checks to finish 2025/01/31 02:00:06 DEBUG : empty space: Unchanged skipping 2025/01/31 02:00:06 DEBUG : potato3: Sizes differ (src 68 vs dst 60) 2025/01/31 02:00:06 INFO : empty space: Deleted 2025/01/31 02:00:06 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-heponev5kige': Waiting for transfers to finish 2025/01/31 02:00:07 INFO : potato3: Deleted 2025/01/31 02:00:07 INFO : potato2: Moved (server-side) 2025/01/31 02:00:08 INFO : potato3: Moved (server-side) 2025/01/31 02:00:08 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-sebutay9ceco" 2025/01/31 02:00:08 DEBUG : Config file has changed externally - reloading 2025/01/31 02:00:08 DEBUG : Creating backend with remote "TestDrive:crypt/tlvme77kctfpt0ep3t05mn3qn172pntej70h6ll7ggr7fravo5vg" 2025/01/31 02:00:09 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-sebutay9ceco': Using server-side directory move 2025/01/31 02:00:10 INFO : Encrypted drive 'TestCryptDrive:rclone-test-sebutay9ceco': Server side directory move succeeded 2025/01/31 02:00:11 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-sebutay9ceco': Purge remote 2025/01/31 02:00:12 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-heponev5kige': Purge remote 2025/01/31 02:00:12 NOTICE: purge failed: directory not found --- PASS: TestServerSideMove (16.90s) === RUN TestServerSideMoveWithFilter run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-payebeb7toku'", Local "Local file system at /tmp/rclone695105756", Modify Window "1ms" 2025/01/31 02:00:12 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-vifukud5tosa" 2025/01/31 02:00:12 DEBUG : Creating backend with remote "TestDrive:crypt/hppb2t161c4on1ufmbq074n14rds7a17vormo0f16c4mi4j7n69g" 2025/01/31 02:00:15 DEBUG : potato2: md5 = d047babe82121eef7ac5c4a5bd063b9c OK 2025/01/31 02:00:17 DEBUG : empty space: md5 = ec44c52c9b1fb144e4e27627a4cebe9a OK 2025/01/31 02:00:18 DEBUG : potato3: md5 = b98d243f09887c90388b4aec3c87b307 OK sync_test.go:1705: Server side move (if possible) Encrypted drive 'TestCryptDrive:rclone-test-payebeb7toku' -> Encrypted drive 'TestCryptDrive:rclone-test-vifukud5tosa' 2025/01/31 02:00:21 DEBUG : empty space: md5 = 037b737ff7ab7fdf8d9fc6c23c4f9cf5 OK 2025/01/31 02:00:23 DEBUG : potato3: md5 = 3318f44b73ee6252631ef3ec5f95f1d5 OK 2025/01/31 02:00:23 DEBUG : empty space: Excluded (Size Filter) 2025/01/31 02:00:23 DEBUG : empty space: Excluded (Size Filter) 2025/01/31 02:00:23 DEBUG : potato2: Need to transfer - File not found at Destination 2025/01/31 02:00:23 DEBUG : potato3: Sizes differ (src 68 vs dst 60) 2025/01/31 02:00:23 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vifukud5tosa': Waiting for checks to finish 2025/01/31 02:00:23 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vifukud5tosa': Waiting for transfers to finish 2025/01/31 02:00:24 INFO : potato3: Deleted 2025/01/31 02:00:24 INFO : potato2: Moved (server-side) 2025/01/31 02:00:24 INFO : potato3: Moved (server-side) 2025/01/31 02:00:25 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-hugucov3mepa" 2025/01/31 02:00:25 DEBUG : Config file has changed externally - reloading 2025/01/31 02:00:25 DEBUG : Creating backend with remote "TestDrive:crypt/2r55qf60ieintrjdkk2318vm2dskn85t1vnj4ep5v3vbquhs10v0" 2025/01/31 02:00:26 DEBUG : empty space: Excluded (Size Filter) 2025/01/31 02:00:26 DEBUG : potato2: Need to transfer - File not found at Destination 2025/01/31 02:00:26 DEBUG : potato3: Need to transfer - File not found at Destination 2025/01/31 02:00:26 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hugucov3mepa': Waiting for checks to finish 2025/01/31 02:00:26 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hugucov3mepa': Waiting for transfers to finish 2025/01/31 02:00:28 INFO : potato3: Moved (server-side) 2025/01/31 02:00:29 INFO : potato2: Moved (server-side) 2025/01/31 02:00:29 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-hugucov3mepa': Purge remote 2025/01/31 02:00:30 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-vifukud5tosa': Purge remote --- PASS: TestServerSideMoveWithFilter (19.63s) === RUN TestServerSideMoveDeleteEmptySourceDirs run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-payebeb7toku'", Local "Local file system at /tmp/rclone695105756", Modify Window "1ms" 2025/01/31 02:00:32 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-fixakoq6nosi" 2025/01/31 02:00:32 DEBUG : Creating backend with remote "TestDrive:crypt/33n0k0vl1g4ucbpu5kkc4ppifi3pc63tvtc7l20c8hok1ne30nt0" 2025/01/31 02:00:35 DEBUG : potato2: md5 = ef1753058c8b675fd1792629a6bc6e2c OK 2025/01/31 02:00:37 DEBUG : empty space: md5 = e932286fef5854024706f2b7574fc84c OK 2025/01/31 02:00:38 DEBUG : potato3: md5 = 03a4faf9c6faa7dcef9119afbbf8dfcf OK 2025/01/31 02:00:38 INFO : tomatoDir: Making directory sync_test.go:1705: Server side move (if possible) Encrypted drive 'TestCryptDrive:rclone-test-payebeb7toku' -> Encrypted drive 'TestCryptDrive:rclone-test-fixakoq6nosi' 2025/01/31 02:00:42 DEBUG : empty space: md5 = d423a0b6a2e062b91788868e8021ff00 OK 2025/01/31 02:00:44 DEBUG : potato3: md5 = 361ef0d014bdd994d39116644285b1d1 OK 2025/01/31 02:00:44 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-fixakoq6nosi': Using server-side directory move 2025/01/31 02:00:44 INFO : Encrypted drive 'TestCryptDrive:rclone-test-fixakoq6nosi': Server side directory move failed - fallback to file moves: can't copy directory - destination already exists 2025/01/31 02:00:45 DEBUG : potato2: Need to transfer - File not found at Destination 2025/01/31 02:00:45 DEBUG : Added delayed dir = "tomatoDir", newDst= 2025/01/31 02:00:45 DEBUG : empty space: Size and modification time the same (differ by 0s, within tolerance 1ms) 2025/01/31 02:00:45 DEBUG : empty space: Unchanged skipping 2025/01/31 02:00:45 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-fixakoq6nosi': Waiting for checks to finish 2025/01/31 02:00:45 DEBUG : potato3: Sizes differ (src 68 vs dst 60) 2025/01/31 02:00:45 INFO : empty space: Deleted 2025/01/31 02:00:45 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-fixakoq6nosi': Waiting for transfers to finish 2025/01/31 02:00:45 INFO : potato3: Deleted 2025/01/31 02:00:45 INFO : potato2: Moved (server-side) 2025/01/31 02:00:46 INFO : potato3: Moved (server-side) 2025/01/31 02:00:46 INFO : tomatoDir: Removing directory 2025/01/31 02:00:47 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-payebeb7toku': deleted 1 directories 2025/01/31 02:00:48 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-tevetaz5cexi" 2025/01/31 02:00:48 DEBUG : Creating backend with remote "TestDrive:crypt/ajh1u6652igmk8tdu0f91fte3h2e29v1p6ia753omh1f79052ksg" 2025/01/31 02:00:49 INFO : tomatoDir: Making directory 2025/01/31 02:00:50 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tevetaz5cexi': Using server-side directory move 2025/01/31 02:00:50 INFO : Encrypted drive 'TestCryptDrive:rclone-test-tevetaz5cexi': Server side directory move succeeded 2025/01/31 02:00:52 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tevetaz5cexi': Purge remote 2025/01/31 02:00:52 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-fixakoq6nosi': Purge remote 2025/01/31 02:00:53 NOTICE: purge failed: directory not found --- PASS: TestServerSideMoveDeleteEmptySourceDirs (20.89s) === RUN TestServerSideMoveOverlap run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-payebeb7toku'", Local "Local file system at /tmp/rclone695105756", Modify Window "1ms" sync_test.go:1910: Skipping test as remote supports DirMove --- SKIP: TestServerSideMoveOverlap (0.48s) === RUN TestSyncOverlap run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-payebeb7toku'", Local "Local file system at /tmp/rclone695105756", Modify Window "1ms" 2025/01/31 02:00:53 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-payebeb7toku/rclone-sync-test" 2025/01/31 02:00:54 DEBUG : Creating backend with remote "TestDrive:crypt/3s78bg6469de2de4o25i2dbql3rcb1o5fblcj0r3fdq18f6qbclg/i7355aa0sb89uagn75vfjqr6s3e3e1h2et8in57abn1fe8qfego0" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-payebeb7toku'", Local "Local file system at /tmp/rclone695105756", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-payebeb7toku'", Local "Local file system at /tmp/rclone695105756", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-payebeb7toku'", Local "Local file system at /tmp/rclone695105756", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-payebeb7toku'", Local "Local file system at /tmp/rclone695105756", Modify Window "1ms" --- PASS: TestSyncOverlap (3.89s) === RUN TestSyncOverlapWithFilter run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-payebeb7toku'", Local "Local file system at /tmp/rclone695105756", Modify Window "1ms" 2025/01/31 02:00:57 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-payebeb7toku/rclone-sync-test" 2025/01/31 02:00:57 DEBUG : Creating backend with remote "TestDrive:crypt/3s78bg6469de2de4o25i2dbql3rcb1o5fblcj0r3fdq18f6qbclg/i7355aa0sb89uagn75vfjqr6s3e3e1h2et8in57abn1fe8qfego0" 2025/01/31 02:01:00 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-payebeb7toku/rclone-sync-test-include/layer2" 2025/01/31 02:01:00 DEBUG : Creating backend with remote "TestDrive:crypt/3s78bg6469de2de4o25i2dbql3rcb1o5fblcj0r3fdq18f6qbclg/khf2vlblvnbf9ftevqm0htmss73hj1j5a7q328e4ohrgs7e2loe0/n01jpl9202nn9ec1rb75h0f1c4" 2025/01/31 02:01:03 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-payebeb7toku/rclone-sync-test-ignore-file" 2025/01/31 02:01:03 DEBUG : Creating backend with remote "TestDrive:crypt/3s78bg6469de2de4o25i2dbql3rcb1o5fblcj0r3fdq18f6qbclg/kmf11jujl9uha3tjganvgpkn45bu778hb5vb5riug1c26b38k7sg" 2025/01/31 02:01:08 DEBUG : rclone-sync-test-ignore-file/.ignore: md5 = dd101acc1d4b1e0629c4181879bd5a6d OK 2025/01/31 02:01:10 DEBUG : Added delayed dir = "rclone-sync-test-include", newDst= 2025/01/31 02:01:10 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-payebeb7toku/rclone-sync-test': Waiting for checks to finish 2025/01/31 02:01:10 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-payebeb7toku/rclone-sync-test': Waiting for transfers to finish 2025/01/31 02:01:10 DEBUG : Waiting for deletions to finish 2025/01/31 02:01:10 INFO : There was nothing to transfer 2025/01/31 02:01:11 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-payebeb7toku': Waiting for checks to finish 2025/01/31 02:01:11 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-payebeb7toku': Waiting for transfers to finish 2025/01/31 02:01:11 DEBUG : Waiting for deletions to finish 2025/01/31 02:01:11 INFO : rclone-sync-test-include: Removing directory 2025/01/31 02:01:12 DEBUG : khf2vlblvnbf9ftevqm0htmss73hj1j5a7q328e4ohrgs7e2loe0: Rmdir: contains file: "n01jpl9202nn9ec1rb75h0f1c4" 2025/01/31 02:01:12 DEBUG : rclone-sync-test-include: Failed to Rmdir: directory not empty 2025/01/31 02:01:12 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-payebeb7toku': failed to delete 1 directories 2025/01/31 02:01:12 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-payebeb7toku'", Local "Local file system at /tmp/rclone695105756", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-payebeb7toku'", Local "Local file system at /tmp/rclone695105756", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-payebeb7toku'", Local "Local file system at /tmp/rclone695105756", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-payebeb7toku'", Local "Local file system at /tmp/rclone695105756", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-payebeb7toku'", Local "Local file system at /tmp/rclone695105756", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-payebeb7toku'", Local "Local file system at /tmp/rclone695105756", Modify Window "1ms" 2025/01/31 02:01:14 DEBUG : Added delayed dir = "rclone-sync-test-include", newDst= 2025/01/31 02:01:14 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-payebeb7toku/rclone-sync-test-include/layer2': Waiting for checks to finish 2025/01/31 02:01:14 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-payebeb7toku/rclone-sync-test-include/layer2': Waiting for transfers to finish 2025/01/31 02:01:14 DEBUG : Waiting for deletions to finish 2025/01/31 02:01:14 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-payebeb7toku'", Local "Local file system at /tmp/rclone695105756", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-payebeb7toku'", Local "Local file system at /tmp/rclone695105756", Modify Window "1ms" 2025/01/31 02:01:16 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-payebeb7toku': Waiting for checks to finish 2025/01/31 02:01:16 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-payebeb7toku': Waiting for transfers to finish 2025/01/31 02:01:16 DEBUG : Waiting for deletions to finish 2025/01/31 02:01:16 INFO : rclone-sync-test-include: Removing directory 2025/01/31 02:01:16 DEBUG : khf2vlblvnbf9ftevqm0htmss73hj1j5a7q328e4ohrgs7e2loe0: Rmdir: contains file: "n01jpl9202nn9ec1rb75h0f1c4" 2025/01/31 02:01:16 DEBUG : rclone-sync-test-include: Failed to Rmdir: directory not empty 2025/01/31 02:01:16 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-payebeb7toku': failed to delete 1 directories 2025/01/31 02:01:16 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-payebeb7toku'", Local "Local file system at /tmp/rclone695105756", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-payebeb7toku'", Local "Local file system at /tmp/rclone695105756", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-payebeb7toku'", Local "Local file system at /tmp/rclone695105756", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-payebeb7toku'", Local "Local file system at /tmp/rclone695105756", Modify Window "1ms" 2025/01/31 02:01:18 DEBUG : Added delayed dir = "rclone-sync-test-include", newDst= 2025/01/31 02:01:18 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-payebeb7toku/rclone-sync-test-ignore-file': Waiting for checks to finish 2025/01/31 02:01:18 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-payebeb7toku/rclone-sync-test-ignore-file': Waiting for transfers to finish 2025/01/31 02:01:18 DEBUG : Waiting for deletions to finish 2025/01/31 02:01:18 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-payebeb7toku'", Local "Local file system at /tmp/rclone695105756", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-payebeb7toku'", Local "Local file system at /tmp/rclone695105756", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-payebeb7toku'", Local "Local file system at /tmp/rclone695105756", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-payebeb7toku'", Local "Local file system at /tmp/rclone695105756", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-payebeb7toku'", Local "Local file system at /tmp/rclone695105756", Modify Window "1ms" 2025/01/31 02:01:20 DEBUG : khf2vlblvnbf9ftevqm0htmss73hj1j5a7q328e4ohrgs7e2loe0: Rmdir: contains trashed file: "n01jpl9202nn9ec1rb75h0f1c4" 2025/01/31 02:01:21 DEBUG : kmf11jujl9uha3tjganvgpkn45bu778hb5vb5riug1c26b38k7sg: Rmdir: contains trashed file: "i0t74httmdlljg425j6tg570d8" --- PASS: TestSyncOverlapWithFilter (33.03s) === RUN TestSyncCompareDest run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-payebeb7toku'", Local "Local file system at /tmp/rclone695105756", Modify Window "1ms" 2025/01/31 02:01:30 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-payebeb7toku/dst" 2025/01/31 02:01:30 DEBUG : Creating backend with remote "TestDrive:crypt/3s78bg6469de2de4o25i2dbql3rcb1o5fblcj0r3fdq18f6qbclg/31u3jie661vd5p8j7rtc3hgbh0" 2025/01/31 02:01:32 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-payebeb7toku/CompareDest" 2025/01/31 02:01:32 DEBUG : Creating backend with remote "TestDrive:crypt/3s78bg6469de2de4o25i2dbql3rcb1o5fblcj0r3fdq18f6qbclg/gveqi14airsml4bgu7krj116o8" 2025/01/31 02:01:34 DEBUG : one: Need to transfer - File not found at Destination 2025/01/31 02:01:34 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-payebeb7toku/dst': Waiting for checks to finish 2025/01/31 02:01:34 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-payebeb7toku/dst': Waiting for transfers to finish 2025/01/31 02:01:36 DEBUG : one: md5 = 5848b8314b0b375aeff25b9f309c7968 OK 2025/01/31 02:01:36 INFO : one: Copied (new) 2025/01/31 02:01:36 DEBUG : Waiting for deletions to finish 2025/01/31 02:01:38 DEBUG : one: Sizes differ (src 5 vs dst 3) 2025/01/31 02:01:38 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-payebeb7toku/dst': Waiting for checks to finish 2025/01/31 02:01:38 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-payebeb7toku/dst': Waiting for transfers to finish 2025/01/31 02:01:39 DEBUG : one: md5 = 8bef1aa681f4debbcfe89ecad03f2779 OK 2025/01/31 02:01:39 INFO : one: Copied (replaced existing) 2025/01/31 02:01:39 DEBUG : Waiting for deletions to finish 2025/01/31 02:01:41 DEBUG : dst/one: md5 = e85214650c575abfea68db67a6776d43 OK 2025/01/31 02:01:43 DEBUG : CompareDest/one: md5 = f799f458879e822de68726d45714cf67 OK 2025/01/31 02:01:44 DEBUG : one: Sizes differ (src 5 vs dst 3) 2025/01/31 02:01:44 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-payebeb7toku/dst': Waiting for checks to finish 2025/01/31 02:01:45 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/01/31 02:01:45 DEBUG : one: Destination found in --compare-dest, skipping 2025/01/31 02:01:45 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-payebeb7toku/dst': Waiting for transfers to finish 2025/01/31 02:01:45 DEBUG : Waiting for deletions to finish 2025/01/31 02:01:45 INFO : There was nothing to transfer 2025/01/31 02:01:46 DEBUG : CompareDest/two: md5 = 267dc6fa0bd880e8edb13c51dfdff1a4 OK 2025/01/31 02:01:47 DEBUG : two: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/01/31 02:01:47 DEBUG : two: Destination found in --compare-dest, skipping 2025/01/31 02:01:47 DEBUG : one: Sizes differ (src 5 vs dst 3) 2025/01/31 02:01:47 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-payebeb7toku/dst': Waiting for checks to finish 2025/01/31 02:01:48 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/01/31 02:01:48 DEBUG : one: Destination found in --compare-dest, skipping 2025/01/31 02:01:48 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-payebeb7toku/dst': Waiting for transfers to finish 2025/01/31 02:01:48 DEBUG : Waiting for deletions to finish 2025/01/31 02:01:48 INFO : There was nothing to transfer 2025/01/31 02:01:49 DEBUG : two: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/01/31 02:01:49 DEBUG : two: Destination found in --compare-dest, skipping 2025/01/31 02:01:49 DEBUG : one: Sizes differ (src 5 vs dst 3) 2025/01/31 02:01:49 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-payebeb7toku/dst': Waiting for checks to finish 2025/01/31 02:01:49 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/01/31 02:01:49 DEBUG : one: Destination found in --compare-dest, skipping 2025/01/31 02:01:49 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-payebeb7toku/dst': Waiting for transfers to finish 2025/01/31 02:01:49 DEBUG : Waiting for deletions to finish 2025/01/31 02:01:49 INFO : There was nothing to transfer sync_test.go:2175: No hash on uploaded file so skipping compare timestamp test 2025/01/31 02:01:51 DEBUG : two: Sizes differ (src 5 vs dst 3) 2025/01/31 02:01:51 DEBUG : two: Need to transfer - File not found at Destination 2025/01/31 02:01:51 DEBUG : one: Sizes differ (src 5 vs dst 3) 2025/01/31 02:01:51 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-payebeb7toku/dst': Waiting for checks to finish 2025/01/31 02:01:51 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/01/31 02:01:51 DEBUG : one: Destination found in --compare-dest, skipping 2025/01/31 02:01:51 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-payebeb7toku/dst': Waiting for transfers to finish 2025/01/31 02:01:52 DEBUG : two: md5 = 56415f57c54de75fea0f1b33e27c9f3c OK 2025/01/31 02:01:52 INFO : two: Copied (new) 2025/01/31 02:01:52 DEBUG : Waiting for deletions to finish 2025/01/31 02:01:56 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k" 2025/01/31 02:01:56 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" 2025/01/31 02:01:57 DEBUG : gveqi14airsml4bgu7krj116o8: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k" 2025/01/31 02:01:57 DEBUG : gveqi14airsml4bgu7krj116o8: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" --- PASS: TestSyncCompareDest (27.19s) === RUN TestSyncMultipleCompareDest run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-payebeb7toku'", Local "Local file system at /tmp/rclone695105756", Modify Window "1ms" 2025/01/31 02:02:00 DEBUG : pre-dest1/1: md5 = 3b005f2d76a3eba41616efdbdf89a709 OK 2025/01/31 02:02:03 DEBUG : pre-dest2/2: md5 = 48e64a0639037dd0e263f39ef069426c OK 2025/01/31 02:02:03 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-payebeb7toku/dest" 2025/01/31 02:02:03 DEBUG : Creating backend with remote "TestDrive:crypt/3s78bg6469de2de4o25i2dbql3rcb1o5fblcj0r3fdq18f6qbclg/rg03c1jvnehrrc617i0lnqjddc" 2025/01/31 02:02:05 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-payebeb7toku/pre-dest1" 2025/01/31 02:02:05 DEBUG : Creating backend with remote "TestDrive:crypt/3s78bg6469de2de4o25i2dbql3rcb1o5fblcj0r3fdq18f6qbclg/bbnblvh6k061ssopqrp18kd7gc" 2025/01/31 02:02:05 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-payebeb7toku/pre-dest2" 2025/01/31 02:02:05 DEBUG : Creating backend with remote "TestDrive:crypt/3s78bg6469de2de4o25i2dbql3rcb1o5fblcj0r3fdq18f6qbclg/dgicm1h6b5ejvlltm8eeif0bnk" 2025/01/31 02:02:07 DEBUG : 1: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/01/31 02:02:07 DEBUG : 1: Destination found in --compare-dest, skipping 2025/01/31 02:02:07 DEBUG : 2: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/01/31 02:02:07 DEBUG : 2: Destination found in --compare-dest, skipping 2025/01/31 02:02:08 DEBUG : 3: Need to transfer - File not found at Destination 2025/01/31 02:02:08 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-payebeb7toku/dest': Waiting for checks to finish 2025/01/31 02:02:08 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-payebeb7toku/dest': Waiting for transfers to finish 2025/01/31 02:02:10 DEBUG : 3: md5 = acc7908c2b80f52030d7af739f9df523 OK 2025/01/31 02:02:10 INFO : 3: Copied (new) 2025/01/31 02:02:10 DEBUG : Waiting for deletions to finish 2025/01/31 02:02:13 DEBUG : dgicm1h6b5ejvlltm8eeif0bnk: Rmdir: contains trashed file: "1ghu8geql9vrl726n32nrf65bc" 2025/01/31 02:02:14 DEBUG : bbnblvh6k061ssopqrp18kd7gc: Rmdir: contains trashed file: "skbfko3oil7es0lj68ob574sro" 2025/01/31 02:02:15 DEBUG : rg03c1jvnehrrc617i0lnqjddc: Rmdir: contains trashed file: "g072p7hmjchlnj0gibe64c1epg" --- PASS: TestSyncMultipleCompareDest (18.41s) === RUN TestSyncCopyDest run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-payebeb7toku'", Local "Local file system at /tmp/rclone695105756", Modify Window "1ms" 2025/01/31 02:02:16 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-payebeb7toku/dst" 2025/01/31 02:02:16 DEBUG : Creating backend with remote "TestDrive:crypt/3s78bg6469de2de4o25i2dbql3rcb1o5fblcj0r3fdq18f6qbclg/31u3jie661vd5p8j7rtc3hgbh0" 2025/01/31 02:02:17 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-payebeb7toku/CopyDest" 2025/01/31 02:02:18 DEBUG : Creating backend with remote "TestDrive:crypt/3s78bg6469de2de4o25i2dbql3rcb1o5fblcj0r3fdq18f6qbclg/d09o6po3f7bm6ce32vdgs8h9ls" 2025/01/31 02:02:20 DEBUG : one: Need to transfer - File not found at Destination 2025/01/31 02:02:20 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-payebeb7toku/dst': Waiting for checks to finish 2025/01/31 02:02:20 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-payebeb7toku/dst': Waiting for transfers to finish 2025/01/31 02:02:22 DEBUG : one: md5 = ec552342700b5341dd574fc6c6e8b9ba OK 2025/01/31 02:02:22 INFO : one: Copied (new) 2025/01/31 02:02:22 DEBUG : Waiting for deletions to finish 2025/01/31 02:02:23 DEBUG : one: Sizes differ (src 5 vs dst 3) 2025/01/31 02:02:23 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-payebeb7toku/dst': Waiting for checks to finish 2025/01/31 02:02:23 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-payebeb7toku/dst': Waiting for transfers to finish 2025/01/31 02:02:25 DEBUG : one: md5 = d572cedbd64430d7152cd73b30030130 OK 2025/01/31 02:02:25 INFO : one: Copied (replaced existing) 2025/01/31 02:02:25 DEBUG : Waiting for deletions to finish 2025/01/31 02:02:27 DEBUG : dst/one: md5 = 7e2a76ab23a551b942a57942d00e4104 OK 2025/01/31 02:02:29 DEBUG : CopyDest/one: md5 = ab2be4167e2a5590759e6b953f9d98a6 OK 2025/01/31 02:02:30 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-payebeb7toku/BackupDir" 2025/01/31 02:02:30 DEBUG : Creating backend with remote "TestDrive:crypt/3s78bg6469de2de4o25i2dbql3rcb1o5fblcj0r3fdq18f6qbclg/s6dbk3lfi7c9kfvo6j7bla9m0g" 2025/01/31 02:02:32 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-payebeb7toku/dst': Waiting for checks to finish 2025/01/31 02:02:32 DEBUG : one: Sizes differ (src 5 vs dst 3) 2025/01/31 02:02:32 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/01/31 02:02:32 DEBUG : one: Sizes differ (src 5 vs dst 3) 2025/01/31 02:02:34 INFO : one: Moved (server-side) 2025/01/31 02:02:36 INFO : one: Copied (server-side copy) 2025/01/31 02:02:36 DEBUG : one: Destination found in --copy-dest, using server-side copy 2025/01/31 02:02:36 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-payebeb7toku/dst': Waiting for transfers to finish 2025/01/31 02:02:36 DEBUG : Waiting for deletions to finish 2025/01/31 02:02:38 DEBUG : CopyDest/two: md5 = de78eae781d9a5d180c25beafcc76340 OK 2025/01/31 02:02:39 DEBUG : two: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/01/31 02:02:40 INFO : two: Copied (server-side copy) 2025/01/31 02:02:40 DEBUG : two: Destination found in --copy-dest, using server-side copy 2025/01/31 02:02:40 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/01/31 02:02:40 DEBUG : one: Unchanged skipping 2025/01/31 02:02:40 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-payebeb7toku/dst': Waiting for checks to finish 2025/01/31 02:02:40 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-payebeb7toku/dst': Waiting for transfers to finish 2025/01/31 02:02:40 DEBUG : Waiting for deletions to finish 2025/01/31 02:02:41 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/01/31 02:02:41 DEBUG : one: Unchanged skipping 2025/01/31 02:02:41 DEBUG : two: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/01/31 02:02:41 DEBUG : two: Unchanged skipping 2025/01/31 02:02:41 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-payebeb7toku/dst': Waiting for checks to finish 2025/01/31 02:02:41 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-payebeb7toku/dst': Waiting for transfers to finish 2025/01/31 02:02:41 DEBUG : Waiting for deletions to finish 2025/01/31 02:02:41 INFO : There was nothing to transfer 2025/01/31 02:02:43 DEBUG : CopyDest/three: md5 = b09fda9a209d5512e1ee0ee195d49596 OK 2025/01/31 02:02:44 DEBUG : three: Sizes differ (src 7 vs dst 5) 2025/01/31 02:02:44 DEBUG : three: Destination not found in --copy-dest 2025/01/31 02:02:44 DEBUG : three: Need to transfer - File not found at Destination 2025/01/31 02:02:44 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/01/31 02:02:44 DEBUG : one: Unchanged skipping 2025/01/31 02:02:44 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-payebeb7toku/dst': Waiting for checks to finish 2025/01/31 02:02:44 DEBUG : two: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2025/01/31 02:02:44 DEBUG : two: Unchanged skipping 2025/01/31 02:02:44 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-payebeb7toku/dst': Waiting for transfers to finish 2025/01/31 02:02:45 DEBUG : three: md5 = 92f1522029f98c5c2c3e3eb05024a740 OK 2025/01/31 02:02:45 INFO : three: Copied (new) 2025/01/31 02:02:45 DEBUG : Waiting for deletions to finish 2025/01/31 02:02:51 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "b6jdmn2b1adrhc8vikh7edr9os" 2025/01/31 02:02:51 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" 2025/01/31 02:02:51 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k" 2025/01/31 02:02:51 DEBUG : d09o6po3f7bm6ce32vdgs8h9ls: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k" 2025/01/31 02:02:51 DEBUG : d09o6po3f7bm6ce32vdgs8h9ls: Rmdir: contains trashed file: "b6jdmn2b1adrhc8vikh7edr9os" 2025/01/31 02:02:51 DEBUG : d09o6po3f7bm6ce32vdgs8h9ls: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" 2025/01/31 02:02:52 DEBUG : s6dbk3lfi7c9kfvo6j7bla9m0g: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" --- PASS: TestSyncCopyDest (37.22s) === RUN TestSyncBackupDir run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-payebeb7toku'", Local "Local file system at /tmp/rclone695105756", Modify Window "1ms" 2025/01/31 02:02:56 DEBUG : dst/one: md5 = fadd083d3885360f9d666cb26a66a4e6 OK 2025/01/31 02:02:57 DEBUG : dst/two: md5 = 148a003e7849747a4fe88a105016c60d OK 2025/01/31 02:02:59 DEBUG : dst/three.txt: md5 = 1ffcff47cf327da8e7a6c156160e728a OK 2025/01/31 02:02:59 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-payebeb7toku/dst" 2025/01/31 02:02:59 DEBUG : Config file has changed externally - reloading 2025/01/31 02:03:00 DEBUG : Creating backend with remote "TestDrive:crypt/3s78bg6469de2de4o25i2dbql3rcb1o5fblcj0r3fdq18f6qbclg/31u3jie661vd5p8j7rtc3hgbh0" 2025/01/31 02:03:00 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-payebeb7toku/backup" 2025/01/31 02:03:00 DEBUG : Creating backend with remote "TestDrive:crypt/3s78bg6469de2de4o25i2dbql3rcb1o5fblcj0r3fdq18f6qbclg/1nrff024r7pq65ecp72fc28jb0" 2025/01/31 02:03:02 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-payebeb7toku/dst': Waiting for checks to finish 2025/01/31 02:03:02 DEBUG : one: Sizes differ (src 4 vs dst 3) 2025/01/31 02:03:02 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/01/31 02:03:02 DEBUG : two: Unchanged skipping 2025/01/31 02:03:04 INFO : one: Moved (server-side) 2025/01/31 02:03:04 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-payebeb7toku/dst': Waiting for transfers to finish 2025/01/31 02:03:06 DEBUG : one: md5 = 03c836580de0b1a88d8f8c01329534f5 OK 2025/01/31 02:03:06 INFO : one: Copied (new) 2025/01/31 02:03:06 DEBUG : Waiting for deletions to finish 2025/01/31 02:03:07 INFO : three.txt: Moved (server-side) 2025/01/31 02:03:07 INFO : three.txt: Moved into backup dir 2025/01/31 02:03:09 DEBUG : dst/three.txt: md5 = 8622a3fc73dcb6fc0aead09ad64937c8 OK 2025/01/31 02:03:10 DEBUG : one: Sizes differ (src 5 vs dst 4) 2025/01/31 02:03:10 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/01/31 02:03:10 DEBUG : two: Unchanged skipping 2025/01/31 02:03:10 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-payebeb7toku/dst': Waiting for checks to finish 2025/01/31 02:03:10 INFO : one: Deleted 2025/01/31 02:03:11 INFO : one: Moved (server-side) 2025/01/31 02:03:11 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-payebeb7toku/dst': Waiting for transfers to finish 2025/01/31 02:03:13 DEBUG : one: md5 = cde71db1c469b28ec6f1a8045a608b77 OK 2025/01/31 02:03:13 INFO : one: Copied (new) 2025/01/31 02:03:13 DEBUG : Waiting for deletions to finish 2025/01/31 02:03:14 INFO : three.txt: Deleted 2025/01/31 02:03:15 INFO : three.txt: Moved (server-side) 2025/01/31 02:03:15 INFO : three.txt: Moved into backup dir 2025/01/31 02:03:19 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" 2025/01/31 02:03:19 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k" 2025/01/31 02:03:19 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" 2025/01/31 02:03:19 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "tr2hj63d80ftlmvm6a952snjcc" 2025/01/31 02:03:19 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" 2025/01/31 02:03:19 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "tr2hj63d80ftlmvm6a952snjcc" --- PASS: TestSyncBackupDir (27.23s) === RUN TestSyncBackupDirWithSuffix run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-payebeb7toku'", Local "Local file system at /tmp/rclone695105756", Modify Window "1ms" 2025/01/31 02:03:23 DEBUG : dst/one: md5 = 05c24de49dc985a00a742b3873bbd059 OK 2025/01/31 02:03:25 DEBUG : dst/two: md5 = 10315641a1b94bbab9510cbbfff81538 OK 2025/01/31 02:03:26 DEBUG : dst/three.txt: md5 = 2a195dbad9e75e5461cd2cfa4fd0c233 OK 2025/01/31 02:03:27 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-payebeb7toku/dst" 2025/01/31 02:03:27 DEBUG : Creating backend with remote "TestDrive:crypt/3s78bg6469de2de4o25i2dbql3rcb1o5fblcj0r3fdq18f6qbclg/31u3jie661vd5p8j7rtc3hgbh0" 2025/01/31 02:03:28 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-payebeb7toku/backup" 2025/01/31 02:03:28 DEBUG : Creating backend with remote "TestDrive:crypt/3s78bg6469de2de4o25i2dbql3rcb1o5fblcj0r3fdq18f6qbclg/1nrff024r7pq65ecp72fc28jb0" 2025/01/31 02:03:29 DEBUG : one: Sizes differ (src 4 vs dst 3) 2025/01/31 02:03:29 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/01/31 02:03:29 DEBUG : two: Unchanged skipping 2025/01/31 02:03:29 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-payebeb7toku/dst': Waiting for checks to finish 2025/01/31 02:03:32 INFO : one: Moved (server-side) to: one.bak 2025/01/31 02:03:32 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-payebeb7toku/dst': Waiting for transfers to finish 2025/01/31 02:03:33 DEBUG : one: md5 = 6e504e4948d214d81d6d036b9c674f19 OK 2025/01/31 02:03:33 INFO : one: Copied (new) 2025/01/31 02:03:33 DEBUG : Waiting for deletions to finish 2025/01/31 02:03:34 INFO : three.txt: Moved (server-side) to: three.txt.bak 2025/01/31 02:03:34 INFO : three.txt: Moved into backup dir 2025/01/31 02:03:37 DEBUG : dst/three.txt: md5 = 0b4a7649579c9f53dbdd79c31c9febd9 OK 2025/01/31 02:03:37 DEBUG : one: Sizes differ (src 5 vs dst 4) 2025/01/31 02:03:37 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/01/31 02:03:37 DEBUG : two: Unchanged skipping 2025/01/31 02:03:37 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-payebeb7toku/dst': Waiting for checks to finish 2025/01/31 02:03:38 INFO : one.bak: Deleted 2025/01/31 02:03:39 INFO : one: Moved (server-side) to: one.bak 2025/01/31 02:03:39 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-payebeb7toku/dst': Waiting for transfers to finish 2025/01/31 02:03:41 DEBUG : one: md5 = ffd42f1f6389acfeaf134046ed4fcf5d OK 2025/01/31 02:03:41 INFO : one: Copied (new) 2025/01/31 02:03:41 DEBUG : Waiting for deletions to finish 2025/01/31 02:03:41 INFO : three.txt.bak: Deleted 2025/01/31 02:03:42 INFO : three.txt: Moved (server-side) to: three.txt.bak 2025/01/31 02:03:42 INFO : three.txt: Moved into backup dir 2025/01/31 02:03:46 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" 2025/01/31 02:03:46 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k" 2025/01/31 02:03:47 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "sk91qgsqfn0r271r2ehsaoc20c" 2025/01/31 02:03:47 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "qltcak2uaegtmcoa8vijdppbp8" 2025/01/31 02:03:47 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "sk91qgsqfn0r271r2ehsaoc20c" 2025/01/31 02:03:47 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "qltcak2uaegtmcoa8vijdppbp8" --- PASS: TestSyncBackupDirWithSuffix (27.21s) === RUN TestSyncBackupDirWithSuffixKeepExtension run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-payebeb7toku'", Local "Local file system at /tmp/rclone695105756", Modify Window "1ms" 2025/01/31 02:03:51 DEBUG : dst/one: md5 = 3b07c817fca52654a459a7816b8f54ca OK 2025/01/31 02:03:52 DEBUG : dst/two: md5 = 585ee42fac9a82c878e7115311bf292c OK 2025/01/31 02:03:54 DEBUG : dst/three.txt: md5 = ec6ef967cf88af3073342a220baac3db OK 2025/01/31 02:03:54 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-payebeb7toku/dst" 2025/01/31 02:03:54 DEBUG : Creating backend with remote "TestDrive:crypt/3s78bg6469de2de4o25i2dbql3rcb1o5fblcj0r3fdq18f6qbclg/31u3jie661vd5p8j7rtc3hgbh0" 2025/01/31 02:03:55 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-payebeb7toku/backup" 2025/01/31 02:03:55 DEBUG : Creating backend with remote "TestDrive:crypt/3s78bg6469de2de4o25i2dbql3rcb1o5fblcj0r3fdq18f6qbclg/1nrff024r7pq65ecp72fc28jb0" 2025/01/31 02:03:57 DEBUG : one: Sizes differ (src 4 vs dst 3) 2025/01/31 02:03:57 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/01/31 02:03:57 DEBUG : two: Unchanged skipping 2025/01/31 02:03:57 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-payebeb7toku/dst': Waiting for checks to finish 2025/01/31 02:03:59 INFO : one: Moved (server-side) to: one-2019-01-01 2025/01/31 02:03:59 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-payebeb7toku/dst': Waiting for transfers to finish 2025/01/31 02:04:01 DEBUG : one: md5 = 5d4c1ae849a9652f7b1891cf33b7b8e4 OK 2025/01/31 02:04:01 INFO : one: Copied (new) 2025/01/31 02:04:01 DEBUG : Waiting for deletions to finish 2025/01/31 02:04:02 INFO : three.txt: Moved (server-side) to: three-2019-01-01.txt 2025/01/31 02:04:02 INFO : three.txt: Moved into backup dir 2025/01/31 02:04:04 DEBUG : dst/three.txt: md5 = daee90338dad54624ea3bfea68d7bbce OK 2025/01/31 02:04:05 DEBUG : one: Sizes differ (src 5 vs dst 4) 2025/01/31 02:04:05 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/01/31 02:04:05 DEBUG : two: Unchanged skipping 2025/01/31 02:04:05 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-payebeb7toku/dst': Waiting for checks to finish 2025/01/31 02:04:05 INFO : one-2019-01-01: Deleted 2025/01/31 02:04:06 INFO : one: Moved (server-side) to: one-2019-01-01 2025/01/31 02:04:06 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-payebeb7toku/dst': Waiting for transfers to finish 2025/01/31 02:04:08 DEBUG : one: md5 = 1983226cce7924f92d27de22e4456f74 OK 2025/01/31 02:04:08 INFO : one: Copied (new) 2025/01/31 02:04:08 DEBUG : Waiting for deletions to finish 2025/01/31 02:04:09 INFO : three-2019-01-01.txt: Deleted 2025/01/31 02:04:10 INFO : three.txt: Moved (server-side) to: three-2019-01-01.txt 2025/01/31 02:04:10 INFO : three.txt: Moved into backup dir 2025/01/31 02:04:13 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" 2025/01/31 02:04:13 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k" 2025/01/31 02:04:14 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "jcjl1bv3ep0v8kt35lqql1co90" 2025/01/31 02:04:14 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "qtq2f6qq4lgpsmj88vb7147qje3prudmtfdtr2342fth58vo9a50" 2025/01/31 02:04:14 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "qtq2f6qq4lgpsmj88vb7147qje3prudmtfdtr2342fth58vo9a50" 2025/01/31 02:04:14 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "jcjl1bv3ep0v8kt35lqql1co90" --- PASS: TestSyncBackupDirWithSuffixKeepExtension (27.28s) === RUN TestSyncBackupDirSuffixOnly run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-payebeb7toku'", Local "Local file system at /tmp/rclone695105756", Modify Window "1ms" 2025/01/31 02:04:17 DEBUG : dst/one: md5 = 52ffb776c9624125e5c70d8149886c04 OK 2025/01/31 02:04:19 DEBUG : dst/two: md5 = 6e855beb1b7bbe6612ddfdb4ff651acc OK 2025/01/31 02:04:20 DEBUG : dst/three.txt: md5 = 7d1d2280dde3234d71f7bcf838b76e7a OK 2025/01/31 02:04:21 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-payebeb7toku/dst" 2025/01/31 02:04:21 DEBUG : Creating backend with remote "TestDrive:crypt/3s78bg6469de2de4o25i2dbql3rcb1o5fblcj0r3fdq18f6qbclg/31u3jie661vd5p8j7rtc3hgbh0" 2025/01/31 02:04:22 DEBUG : one: Sizes differ (src 4 vs dst 3) 2025/01/31 02:04:22 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/01/31 02:04:22 DEBUG : two: Unchanged skipping 2025/01/31 02:04:22 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-payebeb7toku/dst': Waiting for checks to finish 2025/01/31 02:04:23 INFO : one: Moved (server-side) to: one.bak 2025/01/31 02:04:23 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-payebeb7toku/dst': Waiting for transfers to finish 2025/01/31 02:04:24 DEBUG : one: md5 = 4ee3c5b61cfc792c1a6ece98b037ded8 OK 2025/01/31 02:04:24 INFO : one: Copied (new) 2025/01/31 02:04:24 DEBUG : Waiting for deletions to finish 2025/01/31 02:04:25 INFO : three.txt: Moved (server-side) to: three.txt.bak 2025/01/31 02:04:25 INFO : three.txt: Moved into backup dir 2025/01/31 02:04:27 DEBUG : dst/three.txt: md5 = 6624ec8702b741acc21e160fc0da3588 OK 2025/01/31 02:04:28 DEBUG : one.bak: Excluded (Path Filter) 2025/01/31 02:04:28 DEBUG : three.txt.bak: Excluded (Path Filter) 2025/01/31 02:04:28 DEBUG : one: Sizes differ (src 5 vs dst 4) 2025/01/31 02:04:28 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/01/31 02:04:28 DEBUG : two: Unchanged skipping 2025/01/31 02:04:28 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-payebeb7toku/dst': Waiting for checks to finish 2025/01/31 02:04:29 INFO : one.bak: Deleted 2025/01/31 02:04:29 INFO : one: Moved (server-side) to: one.bak 2025/01/31 02:04:29 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-payebeb7toku/dst': Waiting for transfers to finish 2025/01/31 02:04:31 DEBUG : one: md5 = 21130fec9578c2815101e8c5b65b3e90 OK 2025/01/31 02:04:31 INFO : one: Copied (new) 2025/01/31 02:04:31 DEBUG : Waiting for deletions to finish 2025/01/31 02:04:32 INFO : three.txt.bak: Deleted 2025/01/31 02:04:33 INFO : three.txt: Moved (server-side) to: three.txt.bak 2025/01/31 02:04:33 INFO : three.txt: Moved into backup dir 2025/01/31 02:04:36 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" 2025/01/31 02:04:36 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "qltcak2uaegtmcoa8vijdppbp8" 2025/01/31 02:04:36 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "sk91qgsqfn0r271r2ehsaoc20c" 2025/01/31 02:04:36 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "qltcak2uaegtmcoa8vijdppbp8" 2025/01/31 02:04:36 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "sk91qgsqfn0r271r2ehsaoc20c" 2025/01/31 02:04:36 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k" --- PASS: TestSyncBackupDirSuffixOnly (22.07s) === RUN TestSyncSuffix run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-payebeb7toku'", Local "Local file system at /tmp/rclone695105756", Modify Window "1ms" 2025/01/31 02:04:40 DEBUG : dst/one: md5 = 8af63c662f615899c1e401903212714f OK 2025/01/31 02:04:41 DEBUG : dst/two: md5 = c4a89a81af87793c377a22b8df115d3a OK 2025/01/31 02:04:43 DEBUG : dst/three.txt: md5 = e41675260f710ff999a0169e4f8134a0 OK 2025/01/31 02:04:44 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-payebeb7toku/dst" 2025/01/31 02:04:44 DEBUG : Creating backend with remote "TestDrive:crypt/3s78bg6469de2de4o25i2dbql3rcb1o5fblcj0r3fdq18f6qbclg/31u3jie661vd5p8j7rtc3hgbh0" 2025/01/31 02:04:45 DEBUG : one: Sizes differ (src 4 vs dst 3) 2025/01/31 02:04:46 INFO : one: Moved (server-side) to: one.bak 2025/01/31 02:04:48 DEBUG : one: md5 = 1477df524190596a119aa45f24618141 OK 2025/01/31 02:04:48 INFO : one: Copied (new) 2025/01/31 02:04:48 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/01/31 02:04:48 DEBUG : two: Unchanged skipping 2025/01/31 02:04:48 DEBUG : three.txt: Sizes differ (src 6 vs dst 5) 2025/01/31 02:04:49 INFO : three.txt: Moved (server-side) to: three.txt.bak 2025/01/31 02:04:51 DEBUG : three.txt: md5 = 8edac014b82696b15eb9458a94a23797 OK 2025/01/31 02:04:51 INFO : three.txt: Copied (new) 2025/01/31 02:04:52 DEBUG : one: Sizes differ (src 5 vs dst 4) 2025/01/31 02:04:53 INFO : one.bak: Deleted 2025/01/31 02:04:54 INFO : one: Moved (server-side) to: one.bak 2025/01/31 02:04:55 DEBUG : one: md5 = f520aa5d23396449b99486f3d9f52508 OK 2025/01/31 02:04:55 INFO : one: Copied (new) 2025/01/31 02:04:55 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/01/31 02:04:55 DEBUG : two: Unchanged skipping 2025/01/31 02:04:56 DEBUG : three.txt: Sizes differ (src 19 vs dst 6) 2025/01/31 02:04:57 INFO : three.txt.bak: Deleted 2025/01/31 02:04:57 INFO : three.txt: Moved (server-side) to: three.txt.bak 2025/01/31 02:04:59 DEBUG : three.txt: md5 = e67ce8ed888944f10896e5a0c66ff514 OK 2025/01/31 02:04:59 INFO : three.txt: Copied (new) 2025/01/31 02:05:03 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "tr2hj63d80ftlmvm6a952snjcc" 2025/01/31 02:05:03 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" 2025/01/31 02:05:03 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "qltcak2uaegtmcoa8vijdppbp8" 2025/01/31 02:05:03 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k" 2025/01/31 02:05:03 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "sk91qgsqfn0r271r2ehsaoc20c" 2025/01/31 02:05:03 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "sk91qgsqfn0r271r2ehsaoc20c" 2025/01/31 02:05:03 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "qltcak2uaegtmcoa8vijdppbp8" --- PASS: TestSyncSuffix (27.46s) === RUN TestSyncSuffixKeepExtension run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-payebeb7toku'", Local "Local file system at /tmp/rclone695105756", Modify Window "1ms" 2025/01/31 02:05:07 DEBUG : dst/one: md5 = c02e46e761e25d0e97d9e8915d13fc7a OK 2025/01/31 02:05:09 DEBUG : dst/two: md5 = a294213b8d7e6ce5605b227712149703 OK 2025/01/31 02:05:11 DEBUG : dst/three.txt: md5 = 056ae1578b9a5d5e4ba2fd39195365ab OK 2025/01/31 02:05:11 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-payebeb7toku/dst" 2025/01/31 02:05:11 DEBUG : Creating backend with remote "TestDrive:crypt/3s78bg6469de2de4o25i2dbql3rcb1o5fblcj0r3fdq18f6qbclg/31u3jie661vd5p8j7rtc3hgbh0" 2025/01/31 02:05:12 DEBUG : one: Sizes differ (src 4 vs dst 3) 2025/01/31 02:05:13 INFO : one: Moved (server-side) to: one-2019-01-01 2025/01/31 02:05:15 DEBUG : one: md5 = bf7e9fa8659c5c63022e7bee8c0ca6f6 OK 2025/01/31 02:05:15 INFO : one: Copied (new) 2025/01/31 02:05:15 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/01/31 02:05:15 DEBUG : two: Unchanged skipping 2025/01/31 02:05:15 DEBUG : three.txt: Sizes differ (src 6 vs dst 5) 2025/01/31 02:05:16 INFO : three.txt: Moved (server-side) to: three-2019-01-01.txt 2025/01/31 02:05:18 DEBUG : three.txt: md5 = 241eedb43286285ae5144f5f619ddca6 OK 2025/01/31 02:05:18 INFO : three.txt: Copied (new) 2025/01/31 02:05:19 DEBUG : one: Sizes differ (src 5 vs dst 4) 2025/01/31 02:05:20 INFO : one-2019-01-01: Deleted 2025/01/31 02:05:21 INFO : one: Moved (server-side) to: one-2019-01-01 2025/01/31 02:05:23 DEBUG : one: md5 = 491cc1e1a7fe5218576038121fc29acc OK 2025/01/31 02:05:23 INFO : one: Copied (new) 2025/01/31 02:05:23 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/01/31 02:05:23 DEBUG : two: Unchanged skipping 2025/01/31 02:05:23 DEBUG : three.txt: Sizes differ (src 19 vs dst 6) 2025/01/31 02:05:24 INFO : three-2019-01-01.txt: Deleted 2025/01/31 02:05:24 INFO : three.txt: Moved (server-side) to: three-2019-01-01.txt 2025/01/31 02:05:26 DEBUG : three.txt: md5 = f8ed2ae49fa2a26ab3690440f30d6692 OK 2025/01/31 02:05:26 INFO : three.txt: Copied (new) 2025/01/31 02:05:31 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "tr2hj63d80ftlmvm6a952snjcc" 2025/01/31 02:05:31 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" 2025/01/31 02:05:31 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "jcjl1bv3ep0v8kt35lqql1co90" 2025/01/31 02:05:31 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "qtq2f6qq4lgpsmj88vb7147qje3prudmtfdtr2342fth58vo9a50" 2025/01/31 02:05:31 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k" 2025/01/31 02:05:31 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "jcjl1bv3ep0v8kt35lqql1co90" 2025/01/31 02:05:31 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "qtq2f6qq4lgpsmj88vb7147qje3prudmtfdtr2342fth58vo9a50" --- PASS: TestSyncSuffixKeepExtension (27.09s) === RUN TestSyncUTFNorm run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-payebeb7toku'", Local "Local file system at /tmp/rclone695105756", Modify Window "1ms" 2025/01/31 02:05:33 DEBUG : Testêé: md5 = 025c57d16c3c9487b12a9b91a36c148b OK 2025/01/31 02:05:34 DEBUG : Testêé: Sizes differ (src 14 vs dst 18) 2025/01/31 02:05:34 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-payebeb7toku': Waiting for checks to finish 2025/01/31 02:05:34 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-payebeb7toku': Waiting for transfers to finish 2025/01/31 02:05:35 DEBUG : Testêé: md5 = 28273ac6758872b788cdb15d48851a06 OK 2025/01/31 02:05:35 INFO : Testêé: Copied (replaced existing) to: Testêé 2025/01/31 02:05:35 DEBUG : Waiting for deletions to finish --- PASS: TestSyncUTFNorm (4.78s) === RUN TestSyncImmutable run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-payebeb7toku'", Local "Local file system at /tmp/rclone695105756", Modify Window "1ms" 2025/01/31 02:05:37 DEBUG : existing: Need to transfer - File not found at Destination 2025/01/31 02:05:37 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-payebeb7toku': Waiting for checks to finish 2025/01/31 02:05:37 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-payebeb7toku': Waiting for transfers to finish 2025/01/31 02:05:38 DEBUG : existing: md5 = bf5914d6991f9bc31d67aac694d7a5d8 OK 2025/01/31 02:05:38 INFO : existing: Copied (new) 2025/01/31 02:05:38 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-payebeb7toku'", Local "Local file system at /tmp/rclone695105756", Modify Window "1ms" 2025/01/31 02:05:39 DEBUG : existing: Sizes differ (src 8 vs dst 6) 2025/01/31 02:05:39 ERROR : existing: Source and destination exist but do not match: immutable file modified 2025/01/31 02:05:39 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-payebeb7toku': Waiting for checks to finish 2025/01/31 02:05:39 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-payebeb7toku': Waiting for transfers to finish 2025/01/31 02:05:39 ERROR : Encrypted drive 'TestCryptDrive:rclone-test-payebeb7toku': not deleting files as there were IO errors 2025/01/31 02:05:39 ERROR : Encrypted drive 'TestCryptDrive:rclone-test-payebeb7toku': not deleting directories as there were IO errors run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-payebeb7toku'", Local "Local file system at /tmp/rclone695105756", Modify Window "1ms" --- PASS: TestSyncImmutable (4.80s) === RUN TestSyncIgnoreCase run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-payebeb7toku'", Local "Local file system at /tmp/rclone695105756", Modify Window "1ms" 2025/01/31 02:05:43 DEBUG : EXISTING: md5 = 8049a77967274c590de1a96bcd9a5ebd OK 2025/01/31 02:05:44 DEBUG : existing: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/01/31 02:05:44 DEBUG : existing: Unchanged skipping 2025/01/31 02:05:44 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-payebeb7toku': Waiting for checks to finish 2025/01/31 02:05:44 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-payebeb7toku': Waiting for transfers to finish 2025/01/31 02:05:44 DEBUG : Waiting for deletions to finish 2025/01/31 02:05:44 INFO : There was nothing to transfer --- PASS: TestSyncIgnoreCase (4.79s) === RUN TestFixCase run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-payebeb7toku'", Local "Local file system at /tmp/rclone695105756", Modify Window "1ms" sync_test.go:2635: Skipping test as local or remote are case-sensitive --- SKIP: TestFixCase (0.43s) === RUN TestMaxTransfer === RUN TestMaxTransfer/Hard run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-payebeb7toku'", Local "Local file system at /tmp/rclone695105756", 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-payebeb7toku'", Local "Local file system at /tmp/rclone695105756", 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-payebeb7toku'", Local "Local file system at /tmp/rclone695105756", Modify Window "1ms" sync_test.go:2674: This test only runs on local --- PASS: TestMaxTransfer (1.39s) --- SKIP: TestMaxTransfer/Hard (0.51s) --- SKIP: TestMaxTransfer/Soft (0.43s) --- SKIP: TestMaxTransfer/Cautious (0.45s) === RUN TestSyncConcurrentDelete run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-payebeb7toku'", Local "Local file system at /tmp/rclone695105756", Modify Window "1ms" 2025/01/31 02:05:49 DEBUG : both0: md5 = 8f946e7e5e674c224249c4059e4b25d4 OK 2025/01/31 02:05:51 DEBUG : only0: md5 = 309bcb27eadc10038fe259b26f2ec860 OK 2025/01/31 02:05:52 DEBUG : both1: md5 = 7f70983b7319a2424203da767b4c28c7 OK 2025/01/31 02:05:54 DEBUG : only1: md5 = 55101012f488949b0afe419bdc102d21 OK 2025/01/31 02:05:56 DEBUG : both2: md5 = 4aca2165795633f10d3424d6ac8a5f0f OK 2025/01/31 02:05:58 DEBUG : only2: md5 = 1df1eaadbf7d4f2d952607fbbfcd893a OK 2025/01/31 02:05:59 DEBUG : both3: md5 = 30d84360c1f6361f9108ffa13de6bfea OK 2025/01/31 02:06:01 DEBUG : only3: md5 = 5787a323472da18c40f0b373cb75d7bd OK 2025/01/31 02:06:02 DEBUG : both4: md5 = 31da3f4bc59eada46b70f2e9186136ac OK 2025/01/31 02:06:04 DEBUG : only4: md5 = f9292e7c97519346f347970ba4fb8aff OK 2025/01/31 02:06:06 DEBUG : both5: md5 = 65d4b604827cff779e2191f91a5a0ff1 OK 2025/01/31 02:06:07 DEBUG : only5: md5 = 553901c7d1711df4a12d2ef64c86645b OK 2025/01/31 02:06:09 DEBUG : both6: md5 = d0357771dfb2729bdc510dddf8217093 OK 2025/01/31 02:06:10 DEBUG : only6: md5 = 1b6603ca119a6ec08b61879e4c7ceaee OK 2025/01/31 02:06:12 DEBUG : both7: md5 = 8b570f68cd41c98d9f5819b94695fe32 OK 2025/01/31 02:06:14 DEBUG : only7: md5 = e150a2ff9db5db92b44e730f6c36381a OK 2025/01/31 02:06:16 DEBUG : both8: md5 = 0706965350ab0163edee68624bef35f2 OK 2025/01/31 02:06:17 DEBUG : only8: md5 = 5b4dfcf1b4fd6c0c9c3d8cb220535f09 OK 2025/01/31 02:06:19 DEBUG : both9: md5 = 586b6d5d685cfafeb5b445a1ebf84811 OK 2025/01/31 02:06:21 DEBUG : only9: md5 = 5ec642b41a73430447e736b611d3615f OK 2025/01/31 02:06:22 DEBUG : both10: md5 = 862e5fd1563bf58d5c38a6a3e7ad0f2f OK 2025/01/31 02:06:24 DEBUG : only10: md5 = 431777e9555156efd57343879618a232 OK 2025/01/31 02:06:26 DEBUG : both11: md5 = 42b7f8384e26e2eb48e48eb92eb15f9a OK 2025/01/31 02:06:27 DEBUG : only11: md5 = 65e667f67e7f69564486de30c45bffc5 OK 2025/01/31 02:06:29 DEBUG : both12: md5 = d5885ca829e4d36c7abafe8d8e19f22b OK 2025/01/31 02:06:31 DEBUG : only12: md5 = 8b7148970aa973ca4dfff8c37626e08d OK 2025/01/31 02:06:32 DEBUG : both13: md5 = 60fa08474e6f6b52dd429a2ce7baa3a8 OK 2025/01/31 02:06:34 DEBUG : only13: md5 = aa1cfc652b4c792e291806ac427bd22c OK 2025/01/31 02:06:35 DEBUG : both14: md5 = 9561550f4a0c948f0e1e5d44f3bc513c OK 2025/01/31 02:06:37 DEBUG : only14: md5 = 0d3bd3784f4af8564f10fd14519bded0 OK 2025/01/31 02:06:38 DEBUG : both15: md5 = 054584fa872e3661de53c2d1f544d132 OK 2025/01/31 02:06:40 DEBUG : only15: md5 = c6f710a98ba311c6d3ed08781bd4d53e OK 2025/01/31 02:06:42 DEBUG : both16: md5 = 0f6e4ed2f1d88e3aaffc2555e1dea385 OK 2025/01/31 02:06:44 DEBUG : only16: md5 = e26cbd23c9a3b03e93037d5edfb79ca7 OK 2025/01/31 02:06:45 DEBUG : both17: md5 = e7a14a66de0458c4bf25af5063e9f074 OK 2025/01/31 02:06:47 DEBUG : only17: md5 = 7f192bcfc9721708983dca97c170aa07 OK 2025/01/31 02:06:48 DEBUG : both18: md5 = 70272ab5fbffd43f9e52f1da82719d61 OK 2025/01/31 02:06:50 DEBUG : only18: md5 = fece4f1753e9789eec8ec827ea1dff88 OK 2025/01/31 02:06:52 DEBUG : both19: md5 = 45a8ca202a0f48019ec85c0371576c3e OK 2025/01/31 02:06:53 DEBUG : only19: md5 = dcc533bbccd260719d33879a4b8fa308 OK 2025/01/31 02:06:54 DEBUG : both0: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/01/31 02:06:54 DEBUG : both0: Unchanged skipping 2025/01/31 02:06:54 DEBUG : both1: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/01/31 02:06:54 DEBUG : both1: Unchanged skipping 2025/01/31 02:06:54 DEBUG : both10: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/01/31 02:06:54 DEBUG : both10: Unchanged skipping 2025/01/31 02:06:54 DEBUG : both11: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/01/31 02:06:54 DEBUG : both11: Unchanged skipping 2025/01/31 02:06:54 DEBUG : both12: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/01/31 02:06:54 DEBUG : both12: Unchanged skipping 2025/01/31 02:06:54 DEBUG : both13: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/01/31 02:06:54 DEBUG : both13: Unchanged skipping 2025/01/31 02:06:54 DEBUG : both14: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/01/31 02:06:54 DEBUG : both14: Unchanged skipping 2025/01/31 02:06:54 DEBUG : both15: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/01/31 02:06:54 DEBUG : both15: Unchanged skipping 2025/01/31 02:06:54 DEBUG : both16: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/01/31 02:06:54 DEBUG : both16: Unchanged skipping 2025/01/31 02:06:54 DEBUG : both17: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/01/31 02:06:54 DEBUG : both17: Unchanged skipping 2025/01/31 02:06:54 DEBUG : both18: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/01/31 02:06:54 DEBUG : both18: Unchanged skipping 2025/01/31 02:06:54 DEBUG : both19: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/01/31 02:06:54 DEBUG : both19: Unchanged skipping 2025/01/31 02:06:54 DEBUG : both2: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/01/31 02:06:54 DEBUG : both2: Unchanged skipping 2025/01/31 02:06:54 DEBUG : both3: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/01/31 02:06:54 DEBUG : both3: Unchanged skipping 2025/01/31 02:06:54 DEBUG : both4: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/01/31 02:06:54 DEBUG : both4: Unchanged skipping 2025/01/31 02:06:54 DEBUG : both5: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/01/31 02:06:54 DEBUG : both6: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/01/31 02:06:54 DEBUG : both7: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/01/31 02:06:54 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-payebeb7toku': Waiting for checks to finish 2025/01/31 02:06:54 DEBUG : both8: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/01/31 02:06:54 DEBUG : both5: Unchanged skipping 2025/01/31 02:06:54 DEBUG : both9: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/01/31 02:06:54 DEBUG : both9: Unchanged skipping 2025/01/31 02:06:54 DEBUG : both6: Unchanged skipping 2025/01/31 02:06:54 DEBUG : both7: Unchanged skipping 2025/01/31 02:06:54 DEBUG : both8: Unchanged skipping 2025/01/31 02:06:54 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-payebeb7toku': Waiting for transfers to finish 2025/01/31 02:06:54 DEBUG : Waiting for deletions to finish 2025/01/31 02:06:54 INFO : only13: Deleted 2025/01/31 02:06:54 INFO : only0: Deleted 2025/01/31 02:06:54 INFO : only10: Deleted 2025/01/31 02:06:54 INFO : only16: Deleted 2025/01/31 02:06:55 INFO : only19: Deleted 2025/01/31 02:06:55 INFO : only2: Deleted 2025/01/31 02:06:55 INFO : only4: Deleted 2025/01/31 02:06:55 INFO : only5: Deleted 2025/01/31 02:06:55 INFO : only15: Deleted 2025/01/31 02:06:55 INFO : only12: Deleted 2025/01/31 02:06:56 INFO : only14: Deleted 2025/01/31 02:06:56 INFO : only6: Deleted 2025/01/31 02:06:56 INFO : only8: Deleted 2025/01/31 02:06:56 INFO : only11: Deleted 2025/01/31 02:06:56 INFO : only9: Deleted 2025/01/31 02:06:56 INFO : only1: Deleted 2025/01/31 02:06:57 INFO : only18: Deleted 2025/01/31 02:06:57 INFO : only17: Deleted 2025/01/31 02:06:57 INFO : only3: Deleted 2025/01/31 02:06:57 INFO : only7: Deleted 2025/01/31 02:06:57 INFO : There was nothing to transfer run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-payebeb7toku'", Local "Local file system at /tmp/rclone695105756", Modify Window "1ms" --- PASS: TestSyncConcurrentDelete (81.96s) === RUN TestSyncConcurrentTruncate run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-payebeb7toku'", Local "Local file system at /tmp/rclone695105756", Modify Window "1ms" 2025/01/31 02:07:11 DEBUG : both0: md5 = 97738a2fba47dc63db2ab542385f8584 OK 2025/01/31 02:07:13 DEBUG : only0: md5 = 5d2f303c47a33a0e7874a6d930892d99 OK 2025/01/31 02:07:15 DEBUG : both1: md5 = 64a3af5226e2401ae021690c67ccb4fb OK 2025/01/31 02:07:16 DEBUG : only1: md5 = 37a175617c3af0e656b5868a95e2ac65 OK 2025/01/31 02:07:18 DEBUG : both2: md5 = 20dcf852579c19efc4b405604639f936 OK 2025/01/31 02:07:20 DEBUG : only2: md5 = 6398e7effbb9747e455eddea589fac66 OK 2025/01/31 02:07:21 DEBUG : both3: md5 = ef3fa86bad8fb4f2a992488ef56d00bd OK 2025/01/31 02:07:23 DEBUG : only3: md5 = 68b98acbca46e72b98e406ef3fa5667f OK 2025/01/31 02:07:25 DEBUG : both4: md5 = a40253a3e6243c23bab643a26e30e384 OK 2025/01/31 02:07:26 DEBUG : only4: md5 = e7ae19d76a33c7c6dee6fde294563f12 OK 2025/01/31 02:07:28 DEBUG : both5: md5 = 344cf1c454855b9bd7c23b368ae61ae1 OK 2025/01/31 02:07:29 DEBUG : only5: md5 = 866c5dab88188e30ee9a4c97b2c477cb OK 2025/01/31 02:07:31 DEBUG : both6: md5 = cf8457911195a0735e73a5f998859208 OK 2025/01/31 02:07:33 DEBUG : only6: md5 = c0a6365c998a382c5b11d13f9bccecd1 OK 2025/01/31 02:07:34 DEBUG : both7: md5 = 98458f21befbc19ec41dd73c469c2ae8 OK 2025/01/31 02:07:36 DEBUG : only7: md5 = e20f2188a9f2382bfc0c0bc9f184d0b6 OK 2025/01/31 02:07:38 DEBUG : both8: md5 = 1cbfd54b63645eba69a107a7b2ddf6c8 OK 2025/01/31 02:07:40 DEBUG : only8: md5 = bc53fcd6dd4f0888a5656867b52cd2c3 OK 2025/01/31 02:07:41 DEBUG : both9: md5 = e4710656b81c601a577acf19586ce914 OK 2025/01/31 02:07:43 DEBUG : only9: md5 = d6948ef53f3e4ab78504c463f2317519 OK 2025/01/31 02:07:45 DEBUG : both10: md5 = 7edf94dc0a3353629acda3e0e68b621e OK 2025/01/31 02:07:47 DEBUG : only10: md5 = 9ff704bdb7464450c39e5b51a0dade45 OK 2025/01/31 02:07:48 DEBUG : both11: md5 = 9386b1520dfeecbc59ad74896d767278 OK 2025/01/31 02:07:50 DEBUG : only11: md5 = a57b22d51d9da8c091dc81668dd230f0 OK 2025/01/31 02:07:51 DEBUG : both12: md5 = bd8eb1b24207c60025dcef49c2b54051 OK 2025/01/31 02:08:02 DEBUG : only12: md5 = 91de428f113688ea0c736b13fbf954e5 OK 2025/01/31 02:08:04 DEBUG : both13: md5 = 697af7d7923a8df1b09f44415f2e89ec OK 2025/01/31 02:08:06 DEBUG : only13: md5 = e6d4dbd11fb9101802b920d359e81e73 OK 2025/01/31 02:08:07 DEBUG : both14: md5 = 328214c149018b3485307a62bd91b68f OK 2025/01/31 02:08:09 DEBUG : only14: md5 = 4ebfb06cdf83fa349ed05ae965e48d46 OK 2025/01/31 02:08:11 DEBUG : both15: md5 = 4319e44f4f78f4b2e45772fbe299955b OK 2025/01/31 02:08:12 DEBUG : only15: md5 = 2d27dd5fd0ebb5d1cb7ac2a976efdcce OK 2025/01/31 02:08:14 DEBUG : both16: md5 = 4228ce7f40752a70e5cbe41aa92fa7fd OK 2025/01/31 02:08:16 DEBUG : only16: md5 = f9484dab5e7c0fbce85cc7397dcc843e OK 2025/01/31 02:08:17 DEBUG : both17: md5 = 615aef0ee9183136424334aa88581d20 OK 2025/01/31 02:08:19 DEBUG : only17: md5 = fbc781da0d76811c8c659fccfb9cc1ad OK 2025/01/31 02:08:20 DEBUG : both18: md5 = fba09ba84b768d8319689785ccb8b63c OK 2025/01/31 02:08:22 DEBUG : only18: md5 = c8e9d1c13f066721828cb46093daa6cb OK 2025/01/31 02:08:24 DEBUG : both19: md5 = 3743719c52b59778be1553db19ae9c81 OK 2025/01/31 02:08:25 DEBUG : only19: md5 = ccaaa72ec507f2d00930fac787afa833 OK 2025/01/31 02:08:26 DEBUG : both0: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/01/31 02:08:26 DEBUG : both1: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/01/31 02:08:26 DEBUG : both10: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/01/31 02:08:26 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-payebeb7toku': Waiting for checks to finish 2025/01/31 02:08:26 DEBUG : both11: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/01/31 02:08:26 DEBUG : both0: Unchanged skipping 2025/01/31 02:08:26 DEBUG : both12: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/01/31 02:08:26 DEBUG : both12: Unchanged skipping 2025/01/31 02:08:26 DEBUG : both13: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/01/31 02:08:26 DEBUG : both13: Unchanged skipping 2025/01/31 02:08:26 DEBUG : both14: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/01/31 02:08:26 DEBUG : both1: Unchanged skipping 2025/01/31 02:08:26 DEBUG : both15: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/01/31 02:08:26 DEBUG : both15: Unchanged skipping 2025/01/31 02:08:26 DEBUG : both16: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/01/31 02:08:26 DEBUG : both16: Unchanged skipping 2025/01/31 02:08:26 DEBUG : both17: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/01/31 02:08:26 DEBUG : both17: Unchanged skipping 2025/01/31 02:08:26 DEBUG : both18: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/01/31 02:08:26 DEBUG : both18: Unchanged skipping 2025/01/31 02:08:26 DEBUG : both19: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/01/31 02:08:26 DEBUG : both19: Unchanged skipping 2025/01/31 02:08:26 DEBUG : both2: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/01/31 02:08:26 DEBUG : both2: Unchanged skipping 2025/01/31 02:08:26 DEBUG : both3: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/01/31 02:08:26 DEBUG : both3: Unchanged skipping 2025/01/31 02:08:26 DEBUG : both4: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/01/31 02:08:26 DEBUG : both10: Unchanged skipping 2025/01/31 02:08:26 DEBUG : both5: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/01/31 02:08:26 DEBUG : both5: Unchanged skipping 2025/01/31 02:08:26 DEBUG : both6: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/01/31 02:08:26 DEBUG : both6: Unchanged skipping 2025/01/31 02:08:26 DEBUG : both7: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/01/31 02:08:26 DEBUG : both7: Unchanged skipping 2025/01/31 02:08:26 DEBUG : both8: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/01/31 02:08:26 DEBUG : both8: Unchanged skipping 2025/01/31 02:08:26 DEBUG : both9: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2025/01/31 02:08:26 DEBUG : both9: Unchanged skipping 2025/01/31 02:08:26 DEBUG : only0: Sizes differ (src 0 vs dst 6) 2025/01/31 02:08:26 DEBUG : both11: Unchanged skipping 2025/01/31 02:08:26 DEBUG : only1: Sizes differ (src 0 vs dst 6) 2025/01/31 02:08:26 DEBUG : only10: Sizes differ (src 0 vs dst 6) 2025/01/31 02:08:26 DEBUG : both14: Unchanged skipping 2025/01/31 02:08:26 DEBUG : only11: Sizes differ (src 0 vs dst 6) 2025/01/31 02:08:26 DEBUG : both4: Unchanged skipping 2025/01/31 02:08:26 DEBUG : only12: Sizes differ (src 0 vs dst 6) 2025/01/31 02:08:26 DEBUG : only13: Sizes differ (src 0 vs dst 6) 2025/01/31 02:08:26 DEBUG : only14: Sizes differ (src 0 vs dst 6) 2025/01/31 02:08:26 DEBUG : only15: Sizes differ (src 0 vs dst 6) 2025/01/31 02:08:26 DEBUG : only16: Sizes differ (src 0 vs dst 6) 2025/01/31 02:08:26 DEBUG : only17: Sizes differ (src 0 vs dst 6) 2025/01/31 02:08:26 DEBUG : only18: Sizes differ (src 0 vs dst 6) 2025/01/31 02:08:26 DEBUG : only19: Sizes differ (src 0 vs dst 6) 2025/01/31 02:08:26 DEBUG : only2: Sizes differ (src 0 vs dst 6) 2025/01/31 02:08:26 DEBUG : only3: Sizes differ (src 0 vs dst 6) 2025/01/31 02:08:26 DEBUG : only4: Sizes differ (src 0 vs dst 6) 2025/01/31 02:08:26 DEBUG : only5: Sizes differ (src 0 vs dst 6) 2025/01/31 02:08:26 DEBUG : only6: Sizes differ (src 0 vs dst 6) 2025/01/31 02:08:26 DEBUG : only7: Sizes differ (src 0 vs dst 6) 2025/01/31 02:08:26 DEBUG : only8: Sizes differ (src 0 vs dst 6) 2025/01/31 02:08:26 DEBUG : only9: Sizes differ (src 0 vs dst 6) 2025/01/31 02:08:26 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-payebeb7toku': Waiting for transfers to finish 2025/01/31 02:08:27 DEBUG : only14: md5 = 3e048872e7d94ca386840d7b84b66986 OK 2025/01/31 02:08:27 INFO : only14: Copied (replaced existing) 2025/01/31 02:08:27 DEBUG : only1: md5 = 8cc6c3e629de166c8ab692c3ad37692c OK 2025/01/31 02:08:27 INFO : only1: Copied (replaced existing) 2025/01/31 02:08:27 DEBUG : only13: md5 = 638f84b3cb47d4e162bb9b4738c36c6e OK 2025/01/31 02:08:27 INFO : only13: Copied (replaced existing) 2025/01/31 02:08:27 DEBUG : only12: md5 = cf6bac5fc1c69a56ca21175297d350fa OK 2025/01/31 02:08:27 INFO : only12: Copied (replaced existing) 2025/01/31 02:08:28 DEBUG : only17: md5 = 23e52b80f3a9fdaf767a26bda2a004a6 OK 2025/01/31 02:08:28 INFO : only17: Copied (replaced existing) 2025/01/31 02:08:28 DEBUG : only15: md5 = 77a32b6dd7a19439a833dab17ece8563 OK 2025/01/31 02:08:28 INFO : only15: Copied (replaced existing) 2025/01/31 02:08:29 DEBUG : only16: md5 = 4d8569070c944d56941aa8c6e8ec7b5e OK 2025/01/31 02:08:29 INFO : only16: Copied (replaced existing) 2025/01/31 02:08:29 DEBUG : only0: md5 = 3f0d39c46f805361a8519f9b96369caa OK 2025/01/31 02:08:29 INFO : only0: Copied (replaced existing) 2025/01/31 02:08:30 DEBUG : only3: md5 = 134cf988d3b3049a0d62ced21555da96 OK 2025/01/31 02:08:30 INFO : only3: Copied (replaced existing) 2025/01/31 02:08:30 DEBUG : only2: md5 = e758a0d34ab47671aac60583c5a52efe OK 2025/01/31 02:08:30 INFO : only2: Copied (replaced existing) 2025/01/31 02:08:30 DEBUG : only19: md5 = b4c7613b911b7a20c7fcf6b4a171295f OK 2025/01/31 02:08:30 INFO : only19: Copied (replaced existing) 2025/01/31 02:08:30 DEBUG : only4: md5 = 1f79b4e644f78d33f61a9214e2867083 OK 2025/01/31 02:08:30 INFO : only4: Copied (replaced existing) 2025/01/31 02:08:31 DEBUG : only18: md5 = 0e31e656e262cb79269801969a12af8b OK 2025/01/31 02:08:31 INFO : only18: Copied (replaced existing) 2025/01/31 02:08:31 DEBUG : only6: md5 = 31e872d709c72d48c00eead934a725cf OK 2025/01/31 02:08:31 INFO : only6: Copied (replaced existing) 2025/01/31 02:08:31 DEBUG : only10: md5 = e95953f03f24706ff9133f89130eb9da OK 2025/01/31 02:08:31 INFO : only10: Copied (replaced existing) 2025/01/31 02:08:31 DEBUG : only7: md5 = ac8ddc433ae698b07b85e8a72c1157a3 OK 2025/01/31 02:08:31 INFO : only7: Copied (replaced existing) 2025/01/31 02:08:32 DEBUG : only11: md5 = 72429790ac4ae1e61b99cb0a77060559 OK 2025/01/31 02:08:32 INFO : only11: Copied (replaced existing) 2025/01/31 02:08:32 DEBUG : only5: md5 = ca44578cf28c63f43d57c97b38252277 OK 2025/01/31 02:08:32 INFO : only5: Copied (replaced existing) 2025/01/31 02:08:33 DEBUG : only8: md5 = 12f00263af87e81d10a7f130e52ec048 OK 2025/01/31 02:08:33 INFO : only8: Copied (replaced existing) 2025/01/31 02:08:33 DEBUG : only9: md5 = 19aa7f1f8c991f83c262464a0145d7bf OK 2025/01/31 02:08:33 INFO : only9: Copied (replaced existing) 2025/01/31 02:08:33 DEBUG : Waiting for deletions to finish run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-payebeb7toku'", Local "Local file system at /tmp/rclone695105756", Modify Window "1ms" --- PASS: TestSyncConcurrentTruncate (108.27s) === RUN TestNothingToTransferWithEmptyDirs run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-payebeb7toku'", Local "Local file system at /tmp/rclone695105756", Modify Window "1ms" 2025/01/31 02:08:58 INFO : sub dir: Set directory modification time (using DirSetModTime) 2025/01/31 02:08:58 DEBUG : sub dir: Making directory with metadata 2025/01/31 02:08:59 INFO : sub dir: Made directory with metadata (mtime=2011-12-30T12:59:59Z) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-payebeb7toku'", Local "Local file system at /tmp/rclone695105756", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-payebeb7toku'", Local "Local file system at /tmp/rclone695105756", Modify Window "1ms" 2025/01/31 02:09:19 INFO : sub dir2: Set directory modification time (using DirSetModTime) 2025/01/31 02:09:19 INFO : sub dir2: Set directory modification time (using DirSetModTime) 2025/01/31 02:09:19 INFO : sub dirEmpty/sub dirEmpty2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2025/01/31 02:09:19 INFO : sub dirEmpty: Set directory modification time (using DirSetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-payebeb7toku'", Local "Local file system at /tmp/rclone695105756", Modify Window "1ms" 2025/01/31 02:09:34 DEBUG : gcsdkq814sbtppue42dpsbg8ug: Rmdir: contains trashed file: "sjuo65gk5q3r1199jselk9k9o0" 2025/01/31 02:09:35 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/37qp6d1gohacv723ij3brofbu8/i24n0ln37pa2hv8pctddeuh73o: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" 2025/01/31 02:09:36 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/37qp6d1gohacv723ij3brofbu8: Rmdir: contains trashed file: "i24n0ln37pa2hv8pctddeuh73o" 2025/01/31 02:09:37 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "37qp6d1gohacv723ij3brofbu8" 2025/01/31 02:09:38 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak" 2025/01/31 02:09:39 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak" 2025/01/31 02:09:40 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak" 2025/01/31 02:09:40 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak" 2025/01/31 02:09:41 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/4r13oncfa2rsrr82oqhsqv24ns: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" 2025/01/31 02:09:42 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc: Rmdir: contains trashed file: "4r13oncfa2rsrr82oqhsqv24ns" 2025/01/31 02:09:42 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak" 2025/01/31 02:09:43 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestNothingToTransferWithEmptyDirs (47.43s) === RUN TestNothingToTransferWithoutEmptyDirs run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-payebeb7toku'", Local "Local file system at /tmp/rclone695105756", Modify Window "1ms" 2025/01/31 02:09:45 INFO : sub dir: Set directory modification time (using DirSetModTime) 2025/01/31 02:09:45 DEBUG : sub dir: Making directory with metadata 2025/01/31 02:09:46 INFO : sub dir: Made directory with metadata (mtime=2011-12-30T12:59:59Z) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-payebeb7toku'", Local "Local file system at /tmp/rclone695105756", Modify Window "1ms" run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-payebeb7toku'", Local "Local file system at /tmp/rclone695105756", Modify Window "1ms" 2025/01/31 02:10:10 INFO : sub dir2: Set directory modification time (using DirSetModTime) 2025/01/31 02:10:11 INFO : sub dir2: Set directory modification time (using DirSetModTime) 2025/01/31 02:10:11 INFO : sub dirEmpty/sub dirEmpty2: Made directory with metadata (mtime=2011-12-25T12:59:59.123456789Z) 2025/01/31 02:10:11 INFO : sub dirEmpty: Set directory modification time (using DirSetModTime) run.go:180: Remote "Encrypted drive 'TestCryptDrive:rclone-test-payebeb7toku'", Local "Local file system at /tmp/rclone695105756", Modify Window "1ms" 2025/01/31 02:10:25 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/37qp6d1gohacv723ij3brofbu8/i24n0ln37pa2hv8pctddeuh73o: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" 2025/01/31 02:10:26 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/37qp6d1gohacv723ij3brofbu8: Rmdir: contains trashed file: "i24n0ln37pa2hv8pctddeuh73o" 2025/01/31 02:10:27 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "37qp6d1gohacv723ij3brofbu8" 2025/01/31 02:10:28 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak" 2025/01/31 02:10:29 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak" 2025/01/31 02:10:30 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak" 2025/01/31 02:10:31 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/jefmjbgpu25gb7gcub4i80nlak: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak" 2025/01/31 02:10:32 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc/4r13oncfa2rsrr82oqhsqv24ns: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" 2025/01/31 02:10:33 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc: Rmdir: contains trashed file: "4r13oncfa2rsrr82oqhsqv24ns" 2025/01/31 02:10:33 DEBUG : s0tvtpcbgsp8ufdmedqtvlq3hc: Rmdir: contains trashed file: "jefmjbgpu25gb7gcub4i80nlak" 2025/01/31 02:10:34 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestNothingToTransferWithoutEmptyDirs (50.34s) PASS 2025/01/31 02:10:36 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-payebeb7toku': Purge remote "./sync.test -test.v -test.timeout 1h0m0s -remote TestCryptDrive: -verbose -fast-list" - Finished OK in 17m38.259990241s (try 1/5)