"./sync.test -test.v -test.timeout 1h0m0s -remote TestCryptDrive: -verbose" - Starting (try 1/5) 2021/12/01 05:31:33 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-beyemut3qobodab0bifemeh5" 2021/12/01 05:31:33 DEBUG : Using config file from "/home/rclone/.rclone.conf" 2021/12/01 05:31:33 DEBUG : Creating backend with remote "TestDrive:crypt/arh3eumf1lvqc7k624qhttajs1a59mn77ptb70pl7o7pgr4hoe7n4slnp15daij7ucl94ssdmkc00" 2021/12/01 05:31:34 DEBUG : Creating backend with remote "/tmp/rclone1663228036" === RUN TestPipe --- PASS: TestPipe (0.00s) === RUN TestPipeConcurrent --- PASS: TestPipeConcurrent (0.02s) === RUN TestPipeOrderBy === RUN TestPipeOrderBy/#00 === RUN TestPipeOrderBy/size === RUN TestPipeOrderBy/name === RUN TestPipeOrderBy/modtime === RUN TestPipeOrderBy/size,ascending === RUN TestPipeOrderBy/name,asc === RUN TestPipeOrderBy/modtime,ascending === RUN TestPipeOrderBy/size,descending === RUN TestPipeOrderBy/name,desc === RUN TestPipeOrderBy/modtime,descending === RUN TestPipeOrderBy/size,mixed,50 === RUN TestPipeOrderBy/size,mixed,51 --- PASS: TestPipeOrderBy (0.00s) --- PASS: TestPipeOrderBy/#00 (0.00s) --- PASS: TestPipeOrderBy/size (0.00s) --- PASS: TestPipeOrderBy/name (0.00s) --- PASS: TestPipeOrderBy/modtime (0.00s) --- PASS: TestPipeOrderBy/size,ascending (0.00s) --- PASS: TestPipeOrderBy/name,asc (0.00s) --- PASS: TestPipeOrderBy/modtime,ascending (0.00s) --- PASS: TestPipeOrderBy/size,descending (0.00s) --- PASS: TestPipeOrderBy/name,desc (0.00s) --- PASS: TestPipeOrderBy/modtime,descending (0.00s) --- PASS: TestPipeOrderBy/size,mixed,50 (0.00s) --- PASS: TestPipeOrderBy/size,mixed,51 (0.00s) === RUN TestNewLess === RUN TestNewLess/blankOK === RUN TestNewLess/tooManyParts === RUN TestNewLess/tooManyParts2 === RUN TestNewLess/badMixed === RUN TestNewLess/unknownComparison === RUN TestNewLess/unknownSortDirection === RUN TestNewLess/size === RUN TestNewLess/name === RUN TestNewLess/modtime === RUN TestNewLess/size,ascending === RUN TestNewLess/name,asc === RUN TestNewLess/modtime,ascending === RUN TestNewLess/size,descending === RUN TestNewLess/name,desc === RUN TestNewLess/modtime,descending === RUN TestNewLess/modtime,mixed === RUN TestNewLess/modtime,mixed,30 --- PASS: TestNewLess (0.00s) --- PASS: TestNewLess/blankOK (0.00s) --- PASS: TestNewLess/tooManyParts (0.00s) --- PASS: TestNewLess/tooManyParts2 (0.00s) --- PASS: TestNewLess/badMixed (0.00s) --- PASS: TestNewLess/unknownComparison (0.00s) --- PASS: TestNewLess/unknownSortDirection (0.00s) --- PASS: TestNewLess/size (0.00s) --- PASS: TestNewLess/name (0.00s) --- PASS: TestNewLess/modtime (0.00s) --- PASS: TestNewLess/size,ascending (0.00s) --- PASS: TestNewLess/name,asc (0.00s) --- PASS: TestNewLess/modtime,ascending (0.00s) --- PASS: TestNewLess/size,descending (0.00s) --- PASS: TestNewLess/name,desc (0.00s) --- PASS: TestNewLess/modtime,descending (0.00s) --- PASS: TestNewLess/modtime,mixed (0.00s) --- PASS: TestNewLess/modtime,mixed,30 (0.00s) === RUN TestRcCopy rc_test.go:16: Skipping test on non local remote --- SKIP: TestRcCopy (0.00s) === RUN TestRcMove rc_test.go:16: Skipping test on non local remote --- SKIP: TestRcMove (0.00s) === RUN TestRcSync rc_test.go:16: Skipping test on non local remote --- SKIP: TestRcSync (0.00s) === RUN TestCopyWithDryRun run.go:181: Remote "Encrypted drive 'TestCryptDrive:rclone-test-beyemut3qobodab0bifemeh5'", Local "Local file system at /tmp/rclone1663228036", Modify Window "1ms" 2021/12/01 05:31:36 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-beyemut3qobodab0bifemeh5': Waiting for checks to finish 2021/12/01 05:31:36 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-beyemut3qobodab0bifemeh5': Waiting for transfers to finish 2021/12/01 05:31:36 NOTICE: sub dir/hello world: Skipped copy as --dry-run is set (size 11) --- PASS: TestCopyWithDryRun (2.17s) === RUN TestCopy run.go:181: Remote "Encrypted drive 'TestCryptDrive:rclone-test-beyemut3qobodab0bifemeh5'", Local "Local file system at /tmp/rclone1663228036", Modify Window "1ms" 2021/12/01 05:31:37 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-beyemut3qobodab0bifemeh5': Waiting for checks to finish 2021/12/01 05:31:37 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-beyemut3qobodab0bifemeh5': Waiting for transfers to finish 2021/12/01 05:31:39 DEBUG : sub dir/hello world: md5 = 4142010f595f90bc39b47c5d25cb70ab OK 2021/12/01 05:31:39 INFO : sub dir/hello world: Copied (new) 2021/12/01 05:31:42 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestCopy (5.87s) === RUN TestCopyMissingDirectory run.go:181: Remote "Encrypted drive 'TestCryptDrive:rclone-test-beyemut3qobodab0bifemeh5'", Local "Local file system at /tmp/rclone1663228036", Modify Window "1ms" 2021/12/01 05:31:43 DEBUG : Creating backend with remote "/non-existing" 2021/12/01 05:31:43 ERROR : Local file system at /non-existing: error reading source root directory: directory not found 2021/12/01 05:31:43 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-beyemut3qobodab0bifemeh5': Waiting for checks to finish 2021/12/01 05:31:43 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-beyemut3qobodab0bifemeh5': Waiting for transfers to finish --- PASS: TestCopyMissingDirectory (0.83s) === RUN TestCopyNoTraverse run.go:181: Remote "Encrypted drive 'TestCryptDrive:rclone-test-beyemut3qobodab0bifemeh5'", Local "Local file system at /tmp/rclone1663228036", Modify Window "1ms" 2021/12/01 05:31:44 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-beyemut3qobodab0bifemeh5': Waiting for checks to finish 2021/12/01 05:31:44 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-beyemut3qobodab0bifemeh5': Waiting for transfers to finish 2021/12/01 05:31:46 DEBUG : sub dir/hello world: md5 = 97217088d01a860fbc4ef790f366e4d3 OK 2021/12/01 05:31:46 INFO : sub dir/hello world: Copied (new) 2021/12/01 05:31:48 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestCopyNoTraverse (5.93s) === RUN TestCopyCheckFirst run.go:181: Remote "Encrypted drive 'TestCryptDrive:rclone-test-beyemut3qobodab0bifemeh5'", Local "Local file system at /tmp/rclone1663228036", Modify Window "1ms" 2021/12/01 05:31:49 INFO : Encrypted drive 'TestCryptDrive:rclone-test-beyemut3qobodab0bifemeh5': Running all checks before starting transfers 2021/12/01 05:31:50 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-beyemut3qobodab0bifemeh5': Waiting for checks to finish 2021/12/01 05:31:50 INFO : Encrypted drive 'TestCryptDrive:rclone-test-beyemut3qobodab0bifemeh5': Checks finished, now starting transfers 2021/12/01 05:31:50 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-beyemut3qobodab0bifemeh5': Waiting for transfers to finish 2021/12/01 05:31:52 DEBUG : sub dir/hello world: md5 = a5d0d637b736e808fac4264131894dbb OK 2021/12/01 05:31:52 INFO : sub dir/hello world: Copied (new) 2021/12/01 05:31:54 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestCopyCheckFirst (6.08s) === RUN TestSyncNoTraverse run.go:181: Remote "Encrypted drive 'TestCryptDrive:rclone-test-beyemut3qobodab0bifemeh5'", Local "Local file system at /tmp/rclone1663228036", Modify Window "1ms" 2021/12/01 05:31:55 ERROR : Ignoring --no-traverse with sync 2021/12/01 05:31:56 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-beyemut3qobodab0bifemeh5': Waiting for checks to finish 2021/12/01 05:31:56 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-beyemut3qobodab0bifemeh5': Waiting for transfers to finish 2021/12/01 05:31:58 DEBUG : sub dir/hello world: md5 = cc18717dd940694e7f757b335f5f982c OK 2021/12/01 05:31:58 INFO : sub dir/hello world: Copied (new) 2021/12/01 05:31:58 DEBUG : Waiting for deletions to finish 2021/12/01 05:32:01 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestSyncNoTraverse (6.16s) === RUN TestCopyWithDepth run.go:181: Remote "Encrypted drive 'TestCryptDrive:rclone-test-beyemut3qobodab0bifemeh5'", Local "Local file system at /tmp/rclone1663228036", Modify Window "1ms" 2021/12/01 05:32:02 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-beyemut3qobodab0bifemeh5': Waiting for checks to finish 2021/12/01 05:32:02 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-beyemut3qobodab0bifemeh5': Waiting for transfers to finish 2021/12/01 05:32:03 DEBUG : hello world2: md5 = 59bbbed559b6a8a726b7a1da2ad8351c OK 2021/12/01 05:32:03 INFO : hello world2: Copied (new) --- PASS: TestCopyWithDepth (3.43s) === RUN TestCopyWithFilesFrom run.go:181: Remote "Encrypted drive 'TestCryptDrive:rclone-test-beyemut3qobodab0bifemeh5'", Local "Local file system at /tmp/rclone1663228036", Modify Window "1ms" 2021/12/01 05:32:05 DEBUG : hello world2: Excluded 2021/12/01 05:32:05 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-beyemut3qobodab0bifemeh5': Waiting for checks to finish 2021/12/01 05:32:05 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-beyemut3qobodab0bifemeh5': Waiting for transfers to finish 2021/12/01 05:32:07 DEBUG : potato2: md5 = 70f3a8e43d2200750e7f72798fab5e6f OK 2021/12/01 05:32:07 INFO : potato2: Copied (new) --- PASS: TestCopyWithFilesFrom (3.48s) === RUN TestCopyWithFilesFromAndNoTraverse run.go:181: Remote "Encrypted drive 'TestCryptDrive:rclone-test-beyemut3qobodab0bifemeh5'", Local "Local file system at /tmp/rclone1663228036", Modify Window "1ms" 2021/12/01 05:32:09 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-beyemut3qobodab0bifemeh5': Waiting for checks to finish 2021/12/01 05:32:09 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-beyemut3qobodab0bifemeh5': Waiting for transfers to finish 2021/12/01 05:32:10 DEBUG : potato2: md5 = 0fc33db3db00ba976e584131504e35ac OK 2021/12/01 05:32:10 INFO : potato2: Copied (new) --- PASS: TestCopyWithFilesFromAndNoTraverse (3.30s) === RUN TestCopyEmptyDirectories run.go:181: Remote "Encrypted drive 'TestCryptDrive:rclone-test-beyemut3qobodab0bifemeh5'", Local "Local file system at /tmp/rclone1663228036", Modify Window "1ms" 2021/12/01 05:32:12 DEBUG : sub dir2: Making directory 2021/12/01 05:32:12 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-beyemut3qobodab0bifemeh5': Waiting for checks to finish 2021/12/01 05:32:12 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-beyemut3qobodab0bifemeh5': Waiting for transfers to finish 2021/12/01 05:32:15 DEBUG : sub dir/hello world: md5 = 933affdaeb66f89bef87a563256c3ea2 OK 2021/12/01 05:32:15 INFO : sub dir/hello world: Copied (new) 2021/12/01 05:32:15 DEBUG : sub dir2: Making directory 2021/12/01 05:32:16 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-beyemut3qobodab0bifemeh5': copied 1 directories 2021/12/01 05:32:19 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestCopyEmptyDirectories (8.10s) === RUN TestMoveEmptyDirectories run.go:181: Remote "Encrypted drive 'TestCryptDrive:rclone-test-beyemut3qobodab0bifemeh5'", Local "Local file system at /tmp/rclone1663228036", Modify Window "1ms" 2021/12/01 05:32:20 DEBUG : sub dir2: Making directory 2021/12/01 05:32:20 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-beyemut3qobodab0bifemeh5': Waiting for checks to finish 2021/12/01 05:32:20 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-beyemut3qobodab0bifemeh5': Waiting for transfers to finish 2021/12/01 05:32:23 DEBUG : sub dir/hello world: md5 = ba1d7a22134e1bc9e9773b151fd8693f OK 2021/12/01 05:32:23 INFO : sub dir/hello world: Copied (new) 2021/12/01 05:32:23 INFO : sub dir/hello world: Deleted 2021/12/01 05:32:23 DEBUG : sub dir: Making directory 2021/12/01 05:32:23 DEBUG : sub dir2: Making directory 2021/12/01 05:32:24 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-beyemut3qobodab0bifemeh5': copied 2 directories 2021/12/01 05:32:27 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestMoveEmptyDirectories (8.50s) === RUN TestSyncEmptyDirectories run.go:181: Remote "Encrypted drive 'TestCryptDrive:rclone-test-beyemut3qobodab0bifemeh5'", Local "Local file system at /tmp/rclone1663228036", Modify Window "1ms" 2021/12/01 05:32:28 DEBUG : sub dir2: Making directory 2021/12/01 05:32:29 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-beyemut3qobodab0bifemeh5': Waiting for checks to finish 2021/12/01 05:32:29 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-beyemut3qobodab0bifemeh5': Waiting for transfers to finish 2021/12/01 05:32:31 DEBUG : sub dir/hello world: md5 = e3c4cf8e5aa1d2f6a1acf9ce575457ee OK 2021/12/01 05:32:31 INFO : sub dir/hello world: Copied (new) 2021/12/01 05:32:31 DEBUG : sub dir2: Making directory 2021/12/01 05:32:32 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-beyemut3qobodab0bifemeh5': copied 1 directories 2021/12/01 05:32:32 DEBUG : Waiting for deletions to finish 2021/12/01 05:32:35 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestSyncEmptyDirectories (8.03s) === RUN TestServerSideCopy run.go:181: Remote "Encrypted drive 'TestCryptDrive:rclone-test-beyemut3qobodab0bifemeh5'", Local "Local file system at /tmp/rclone1663228036", Modify Window "1ms" 2021/12/01 05:32:39 DEBUG : sub dir/hello world: md5 = 77c6e2ca529401e9ef6d315849bc8914 OK 2021/12/01 05:32:40 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-kapupap7xasuzic7butakov9" 2021/12/01 05:32:40 DEBUG : Creating backend with remote "TestDrive:crypt/4bv5oon6l7u83265o1q211s3lu78ot7kte5lm4t05p4npeso6qenvgkt4bvillg143ba288bao1o2" sync_test.go:275: Server side copy (if possible) Encrypted drive 'TestCryptDrive:rclone-test-beyemut3qobodab0bifemeh5' -> Encrypted drive 'TestCryptDrive:rclone-test-kapupap7xasuzic7butakov9' 2021/12/01 05:32:42 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-kapupap7xasuzic7butakov9': Waiting for checks to finish 2021/12/01 05:32:42 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-kapupap7xasuzic7butakov9': Waiting for transfers to finish 2021/12/01 05:32:45 INFO : sub dir/hello world: Copied (server-side copy) 2021/12/01 05:32:46 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-kapupap7xasuzic7butakov9': Purge remote 2021/12/01 05:32:48 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestServerSideCopy (12.29s) === RUN TestCopyAfterDelete run.go:181: Remote "Encrypted drive 'TestCryptDrive:rclone-test-beyemut3qobodab0bifemeh5'", Local "Local file system at /tmp/rclone1663228036", Modify Window "1ms" 2021/12/01 05:32:51 DEBUG : sub dir/hello world: md5 = 5fc8602150ccca3c673b60993e39a922 OK 2021/12/01 05:32:51 ERROR : : error listing: directory not found 2021/12/01 05:32:52 DEBUG : Local file system at /tmp/rclone1663228036: Making directory 2021/12/01 05:32:52 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-beyemut3qobodab0bifemeh5': Waiting for checks to finish 2021/12/01 05:32:52 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-beyemut3qobodab0bifemeh5': Waiting for transfers to finish 2021/12/01 05:32:54 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestCopyAfterDelete (6.38s) === RUN TestCopyRedownload run.go:181: Remote "Encrypted drive 'TestCryptDrive:rclone-test-beyemut3qobodab0bifemeh5'", Local "Local file system at /tmp/rclone1663228036", Modify Window "1ms" 2021/12/01 05:32:58 DEBUG : sub dir/hello world: md5 = 3597a4fa23046cd4ac6c96d5c948531a OK 2021/12/01 05:32:59 DEBUG : Local file system at /tmp/rclone1663228036: Waiting for checks to finish 2021/12/01 05:32:59 DEBUG : Local file system at /tmp/rclone1663228036: Waiting for transfers to finish 2021/12/01 05:33:00 INFO : sub dir/hello world: Copied (new) 2021/12/01 05:33:01 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" --- PASS: TestCopyRedownload (7.29s) === RUN TestSyncBasedOnCheckSum run.go:181: Remote "Encrypted drive 'TestCryptDrive:rclone-test-beyemut3qobodab0bifemeh5'", Local "Local file system at /tmp/rclone1663228036", Modify Window "1ms" 2021/12/01 05:33:03 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-beyemut3qobodab0bifemeh5': Waiting for checks to finish 2021/12/01 05:33:03 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-beyemut3qobodab0bifemeh5': Waiting for transfers to finish 2021/12/01 05:33:04 DEBUG : check sum: md5 = bea1d354d41baf07e7f6aa045ab0c6d8 OK 2021/12/01 05:33:04 INFO : check sum: Copied (new) 2021/12/01 05:33:04 DEBUG : Waiting for deletions to finish 2021/12/01 05:33:05 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-beyemut3qobodab0bifemeh5': Waiting for checks to finish 2021/12/01 05:33:05 NOTICE: Encrypted drive 'TestCryptDrive:rclone-test-beyemut3qobodab0bifemeh5': --checksum is in use but the source and destination have no hashes in common; falling back to --size-only 2021/12/01 05:33:05 DEBUG : check sum: Size of src and dst objects identical 2021/12/01 05:33:05 DEBUG : check sum: Unchanged skipping 2021/12/01 05:33:05 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-beyemut3qobodab0bifemeh5': Waiting for transfers to finish 2021/12/01 05:33:05 DEBUG : Waiting for deletions to finish 2021/12/01 05:33:05 INFO : There was nothing to transfer --- PASS: TestSyncBasedOnCheckSum (4.01s) === RUN TestSyncSizeOnly run.go:181: Remote "Encrypted drive 'TestCryptDrive:rclone-test-beyemut3qobodab0bifemeh5'", Local "Local file system at /tmp/rclone1663228036", Modify Window "1ms" 2021/12/01 05:33:07 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-beyemut3qobodab0bifemeh5': Waiting for checks to finish 2021/12/01 05:33:07 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-beyemut3qobodab0bifemeh5': Waiting for transfers to finish 2021/12/01 05:33:08 DEBUG : sizeonly: md5 = 1ad70332a9b9c3ffa82209a142021a31 OK 2021/12/01 05:33:08 INFO : sizeonly: Copied (new) 2021/12/01 05:33:08 DEBUG : Waiting for deletions to finish 2021/12/01 05:33:09 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-beyemut3qobodab0bifemeh5': Waiting for checks to finish 2021/12/01 05:33:09 DEBUG : sizeonly: Sizes identical 2021/12/01 05:33:09 DEBUG : sizeonly: Unchanged skipping 2021/12/01 05:33:09 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-beyemut3qobodab0bifemeh5': Waiting for transfers to finish 2021/12/01 05:33:09 DEBUG : Waiting for deletions to finish 2021/12/01 05:33:09 INFO : There was nothing to transfer --- PASS: TestSyncSizeOnly (3.83s) === RUN TestSyncIgnoreSize run.go:181: Remote "Encrypted drive 'TestCryptDrive:rclone-test-beyemut3qobodab0bifemeh5'", Local "Local file system at /tmp/rclone1663228036", Modify Window "1ms" 2021/12/01 05:33:10 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-beyemut3qobodab0bifemeh5': Waiting for checks to finish 2021/12/01 05:33:10 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-beyemut3qobodab0bifemeh5': Waiting for transfers to finish 2021/12/01 05:33:12 DEBUG : ignore-size: md5 = a890837d1dff671b82833aadc9200eb1 OK 2021/12/01 05:33:12 INFO : ignore-size: Copied (new) 2021/12/01 05:33:12 DEBUG : Waiting for deletions to finish 2021/12/01 05:33:13 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-beyemut3qobodab0bifemeh5': Waiting for checks to finish 2021/12/01 05:33:13 DEBUG : ignore-size: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2021/12/01 05:33:13 DEBUG : ignore-size: Unchanged skipping 2021/12/01 05:33:13 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-beyemut3qobodab0bifemeh5': Waiting for transfers to finish 2021/12/01 05:33:13 DEBUG : Waiting for deletions to finish 2021/12/01 05:33:13 INFO : There was nothing to transfer --- PASS: TestSyncIgnoreSize (3.93s) === RUN TestSyncIgnoreTimes run.go:181: Remote "Encrypted drive 'TestCryptDrive:rclone-test-beyemut3qobodab0bifemeh5'", Local "Local file system at /tmp/rclone1663228036", Modify Window "1ms" 2021/12/01 05:33:16 DEBUG : existing: md5 = 5bd7608c2879b2d86bd5a86106209bac OK 2021/12/01 05:33:16 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-beyemut3qobodab0bifemeh5': Waiting for checks to finish 2021/12/01 05:33:16 DEBUG : existing: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2021/12/01 05:33:16 DEBUG : existing: Unchanged skipping 2021/12/01 05:33:16 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-beyemut3qobodab0bifemeh5': Waiting for transfers to finish 2021/12/01 05:33:16 DEBUG : Waiting for deletions to finish 2021/12/01 05:33:16 INFO : There was nothing to transfer 2021/12/01 05:33:17 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-beyemut3qobodab0bifemeh5': Waiting for checks to finish 2021/12/01 05:33:17 DEBUG : existing: Transferring unconditionally as --ignore-times is in use 2021/12/01 05:33:17 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-beyemut3qobodab0bifemeh5': Waiting for transfers to finish 2021/12/01 05:33:18 DEBUG : existing: md5 = 841b34df9e09a761f9079c4319dd30bc OK 2021/12/01 05:33:18 INFO : existing: Copied (replaced existing) 2021/12/01 05:33:18 DEBUG : Waiting for deletions to finish --- PASS: TestSyncIgnoreTimes (5.38s) === RUN TestSyncIgnoreExisting run.go:181: Remote "Encrypted drive 'TestCryptDrive:rclone-test-beyemut3qobodab0bifemeh5'", Local "Local file system at /tmp/rclone1663228036", Modify Window "1ms" 2021/12/01 05:33:20 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-beyemut3qobodab0bifemeh5': Waiting for checks to finish 2021/12/01 05:33:20 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-beyemut3qobodab0bifemeh5': Waiting for transfers to finish 2021/12/01 05:33:21 DEBUG : existing: md5 = 0dabcc41d0b122cfe943fe08ec980a06 OK 2021/12/01 05:33:21 INFO : existing: Copied (new) 2021/12/01 05:33:21 DEBUG : Waiting for deletions to finish 2021/12/01 05:33:22 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-beyemut3qobodab0bifemeh5': Waiting for checks to finish 2021/12/01 05:33:22 DEBUG : existing: Destination exists, skipping 2021/12/01 05:33:22 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-beyemut3qobodab0bifemeh5': Waiting for transfers to finish 2021/12/01 05:33:22 DEBUG : Waiting for deletions to finish 2021/12/01 05:33:22 INFO : There was nothing to transfer --- PASS: TestSyncIgnoreExisting (4.00s) === RUN TestSyncIgnoreErrors run.go:181: Remote "Encrypted drive 'TestCryptDrive:rclone-test-beyemut3qobodab0bifemeh5'", Local "Local file system at /tmp/rclone1663228036", Modify Window "1ms" 2021/12/01 05:33:26 DEBUG : b/potato: md5 = 8231261f9a2133fa32f47878c7d6a1a1 OK 2021/12/01 05:33:29 DEBUG : c/non empty space: md5 = 8e3032912676bab97a027d1db6048ce0 OK 2021/12/01 05:33:29 DEBUG : d: Making directory 2021/12/01 05:33:31 DEBUG : c/non empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2021/12/01 05:33:31 DEBUG : c/non empty space: Unchanged skipping 2021/12/01 05:33:32 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-beyemut3qobodab0bifemeh5': Waiting for checks to finish 2021/12/01 05:33:32 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-beyemut3qobodab0bifemeh5': Waiting for transfers to finish 2021/12/01 05:33:33 DEBUG : a/potato2: md5 = b35b2b84619db3644030e40b0f87fe58 OK 2021/12/01 05:33:33 INFO : a/potato2: Copied (new) 2021/12/01 05:33:33 DEBUG : Waiting for deletions to finish 2021/12/01 05:33:34 INFO : b/potato: Deleted 2021/12/01 05:33:34 INFO : d: Removing directory 2021/12/01 05:33:35 INFO : b: Removing directory 2021/12/01 05:33:35 DEBUG : 32d8ua6196mc1r7qkfog53rkg0: Rmdir: contains trashed file: "2m507n64kafsi59v9q71r281a4" 2021/12/01 05:33:36 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-beyemut3qobodab0bifemeh5': deleted 2 directories 2021/12/01 05:33:39 DEBUG : 3i9du405pfogq3ncai6pg7ouio: Rmdir: contains trashed file: "982d3pss7t5pn0il16r2foj31s" 2021/12/01 05:33:40 DEBUG : 2bsvlrk2ne1lfitm6tttcu0qt8: Rmdir: contains trashed file: "89l8renevh3mji1c8r1p7qn6tg" --- PASS: TestSyncIgnoreErrors (17.27s) === RUN TestSyncAfterChangingModtimeOnly run.go:181: Remote "Encrypted drive 'TestCryptDrive:rclone-test-beyemut3qobodab0bifemeh5'", Local "Local file system at /tmp/rclone1663228036", Modify Window "1ms" 2021/12/01 05:33:42 DEBUG : empty space: md5 = f0c58533d5f127228c902690d988e246 OK 2021/12/01 05:33:43 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-beyemut3qobodab0bifemeh5': Waiting for checks to finish 2021/12/01 05:33:43 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 2021/12/01 05:33:43 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-beyemut3qobodab0bifemeh5': Waiting for transfers to finish 2021/12/01 05:33:43 NOTICE: empty space: Skipped copy as --dry-run is set (size 1) 2021/12/01 05:33:43 DEBUG : Waiting for deletions to finish 2021/12/01 05:33:44 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-beyemut3qobodab0bifemeh5': Waiting for checks to finish 2021/12/01 05:33:44 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 2021/12/01 05:33:44 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-beyemut3qobodab0bifemeh5': Waiting for transfers to finish 2021/12/01 05:33:45 DEBUG : empty space: md5 = 42fb8473458cbd313f143f6ac82910d3 OK 2021/12/01 05:33:45 INFO : empty space: Copied (replaced existing) 2021/12/01 05:33:45 DEBUG : Waiting for deletions to finish --- PASS: TestSyncAfterChangingModtimeOnly (5.58s) === RUN TestSyncAfterChangingModtimeOnlyWithNoUpdateModTime run.go:181: Remote "Encrypted drive 'TestCryptDrive:rclone-test-beyemut3qobodab0bifemeh5'", Local "Local file system at /tmp/rclone1663228036", Modify Window "1ms" sync_test.go:577: Can't check this if no hashes supported --- PASS: TestSyncAfterChangingModtimeOnlyWithNoUpdateModTime (0.52s) === RUN TestSyncDoesntUpdateModtime run.go:181: Remote "Encrypted drive 'TestCryptDrive:rclone-test-beyemut3qobodab0bifemeh5'", Local "Local file system at /tmp/rclone1663228036", Modify Window "1ms" 2021/12/01 05:33:48 DEBUG : foo: md5 = 3e4f8af897cbda51f919d73cb2c4d9f2 OK 2021/12/01 05:33:49 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-beyemut3qobodab0bifemeh5': Waiting for checks to finish 2021/12/01 05:33:49 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 2021/12/01 05:33:49 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-beyemut3qobodab0bifemeh5': Waiting for transfers to finish 2021/12/01 05:33:50 DEBUG : foo: md5 = 8afd34d5611bd33241201f59cb56c8fe OK 2021/12/01 05:33:50 INFO : foo: Copied (replaced existing) 2021/12/01 05:33:50 DEBUG : Waiting for deletions to finish --- PASS: TestSyncDoesntUpdateModtime (4.71s) === RUN TestSyncAfterAddingAFile run.go:181: Remote "Encrypted drive 'TestCryptDrive:rclone-test-beyemut3qobodab0bifemeh5'", Local "Local file system at /tmp/rclone1663228036", Modify Window "1ms" 2021/12/01 05:33:53 DEBUG : empty space: md5 = a796cf59d3b07828a5950b96b16bced1 OK 2021/12/01 05:33:54 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-beyemut3qobodab0bifemeh5': Waiting for checks to finish 2021/12/01 05:33:54 DEBUG : empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2021/12/01 05:33:54 DEBUG : empty space: Unchanged skipping 2021/12/01 05:33:54 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-beyemut3qobodab0bifemeh5': Waiting for transfers to finish 2021/12/01 05:33:55 DEBUG : potato: md5 = 7eaf9ca4a1cca5b446f172841ec363f4 OK 2021/12/01 05:33:55 INFO : potato: Copied (new) 2021/12/01 05:33:55 DEBUG : Waiting for deletions to finish --- PASS: TestSyncAfterAddingAFile (5.98s) === RUN TestSyncAfterChangingFilesSizeOnly run.go:181: Remote "Encrypted drive 'TestCryptDrive:rclone-test-beyemut3qobodab0bifemeh5'", Local "Local file system at /tmp/rclone1663228036", Modify Window "1ms" 2021/12/01 05:33:59 DEBUG : potato: md5 = 56645e21a4e309f16ad257b297fb6160 OK 2021/12/01 05:34:00 DEBUG : potato: Sizes differ (src 21 vs dst 60) 2021/12/01 05:34:00 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-beyemut3qobodab0bifemeh5': Waiting for checks to finish 2021/12/01 05:34:00 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-beyemut3qobodab0bifemeh5': Waiting for transfers to finish 2021/12/01 05:34:01 DEBUG : potato: md5 = 69ef40dc210f2d1190731200642b39ef OK 2021/12/01 05:34:01 INFO : potato: Copied (replaced existing) 2021/12/01 05:34:01 DEBUG : Waiting for deletions to finish --- PASS: TestSyncAfterChangingFilesSizeOnly (4.91s) === RUN TestSyncAfterChangingContentsOnly run.go:181: Remote "Encrypted drive 'TestCryptDrive:rclone-test-beyemut3qobodab0bifemeh5'", Local "Local file system at /tmp/rclone1663228036", Modify Window "1ms" 2021/12/01 05:34:04 DEBUG : potato: md5 = 5d10afde813d9b40e7c612047b317a4e OK 2021/12/01 05:34:05 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-beyemut3qobodab0bifemeh5': Waiting for checks to finish 2021/12/01 05:34:05 DEBUG : potato: Modification times differ by 119h59m59.876543211s: 2011-12-25 12:59:59.123456789 +0000 UTC, 2011-12-30 12:59:59 +0000 UTC 2021/12/01 05:34:05 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-beyemut3qobodab0bifemeh5': Waiting for transfers to finish 2021/12/01 05:34:06 DEBUG : potato: md5 = c180f8a14e512b6e2b2379f101965640 OK 2021/12/01 05:34:06 INFO : potato: Copied (replaced existing) 2021/12/01 05:34:06 DEBUG : Waiting for deletions to finish --- PASS: TestSyncAfterChangingContentsOnly (4.82s) === RUN TestSyncAfterRemovingAFileAndAddingAFileDryRun run.go:181: Remote "Encrypted drive 'TestCryptDrive:rclone-test-beyemut3qobodab0bifemeh5'", Local "Local file system at /tmp/rclone1663228036", Modify Window "1ms" 2021/12/01 05:34:09 DEBUG : potato: md5 = 5cc91f90e34433bdc61a93062acec459 OK 2021/12/01 05:34:11 DEBUG : empty space: md5 = 65855465570d2dccfba9fae88cd633c7 OK 2021/12/01 05:34:11 NOTICE: potato2: Skipped copy as --dry-run is set (size 60) 2021/12/01 05:34:11 DEBUG : empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2021/12/01 05:34:11 DEBUG : empty space: Unchanged skipping 2021/12/01 05:34:11 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-beyemut3qobodab0bifemeh5': Waiting for checks to finish 2021/12/01 05:34:11 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-beyemut3qobodab0bifemeh5': Waiting for transfers to finish 2021/12/01 05:34:11 DEBUG : Waiting for deletions to finish 2021/12/01 05:34:11 NOTICE: potato: Skipped delete as --dry-run is set (size 21) --- PASS: TestSyncAfterRemovingAFileAndAddingAFileDryRun (5.77s) === RUN TestSyncAfterRemovingAFileAndAddingAFile run.go:181: Remote "Encrypted drive 'TestCryptDrive:rclone-test-beyemut3qobodab0bifemeh5'", Local "Local file system at /tmp/rclone1663228036", Modify Window "1ms" 2021/12/01 05:34:18 DEBUG : potato: md5 = 1963bbbb2e059b76845b83a4b4975aa3 OK 2021/12/01 05:34:19 DEBUG : empty space: md5 = ed888c638d84873f6318973bc44dd3ad OK 2021/12/01 05:34:20 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-beyemut3qobodab0bifemeh5': Waiting for checks to finish 2021/12/01 05:34:20 DEBUG : empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2021/12/01 05:34:20 DEBUG : empty space: Unchanged skipping 2021/12/01 05:34:20 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-beyemut3qobodab0bifemeh5': Waiting for transfers to finish 2021/12/01 05:34:21 DEBUG : potato2: md5 = 801765b45349fe3f9c0fb96e33caaef4 OK 2021/12/01 05:34:21 INFO : potato2: Copied (new) 2021/12/01 05:34:21 DEBUG : Waiting for deletions to finish 2021/12/01 05:34:22 INFO : potato: Deleted --- PASS: TestSyncAfterRemovingAFileAndAddingAFile (11.21s) === RUN TestSyncAfterRemovingAFileAndAddingAFileSubDir run.go:181: Remote "Encrypted drive 'TestCryptDrive:rclone-test-beyemut3qobodab0bifemeh5'", Local "Local file system at /tmp/rclone1663228036", Modify Window "1ms" 2021/12/01 05:34:27 DEBUG : b/potato: md5 = de5c61c6b810d319590d1edc27d02da5 OK 2021/12/01 05:34:29 DEBUG : c/non empty space: md5 = 5e8b3aaf53dfd4f3d7083a6d2980bc8f OK 2021/12/01 05:34:29 DEBUG : d: Making directory 2021/12/01 05:34:30 DEBUG : d/e: Making directory 2021/12/01 05:34:33 DEBUG : c/non empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2021/12/01 05:34:33 DEBUG : c/non empty space: Unchanged skipping 2021/12/01 05:34:34 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-beyemut3qobodab0bifemeh5': Waiting for checks to finish 2021/12/01 05:34:34 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-beyemut3qobodab0bifemeh5': Waiting for transfers to finish 2021/12/01 05:34:35 DEBUG : a/potato2: md5 = 63ad2dd1dc629c51c1d93552aff0b8e4 OK 2021/12/01 05:34:35 INFO : a/potato2: Copied (new) 2021/12/01 05:34:35 DEBUG : Waiting for deletions to finish 2021/12/01 05:34:36 INFO : b/potato: Deleted 2021/12/01 05:34:36 INFO : d/e: Removing directory 2021/12/01 05:34:37 INFO : d: Removing directory 2021/12/01 05:34:37 DEBUG : ka6id8d20d3s5ktapedlphgta8: Rmdir: contains trashed file: "r8sppajuabeak3sbgj2ak8vuf8" 2021/12/01 05:34:38 INFO : b: Removing directory 2021/12/01 05:34:38 DEBUG : 32d8ua6196mc1r7qkfog53rkg0: Rmdir: contains trashed file: "2m507n64kafsi59v9q71r281a4" 2021/12/01 05:34:39 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-beyemut3qobodab0bifemeh5': deleted 3 directories 2021/12/01 05:34:42 DEBUG : 3i9du405pfogq3ncai6pg7ouio: Rmdir: contains trashed file: "982d3pss7t5pn0il16r2foj31s" 2021/12/01 05:34:43 DEBUG : 2bsvlrk2ne1lfitm6tttcu0qt8: Rmdir: contains trashed file: "89l8renevh3mji1c8r1p7qn6tg" --- PASS: TestSyncAfterRemovingAFileAndAddingAFileSubDir (19.20s) === RUN TestSyncAfterRemovingAFileAndAddingAFileSubDirWithErrors run.go:181: Remote "Encrypted drive 'TestCryptDrive:rclone-test-beyemut3qobodab0bifemeh5'", Local "Local file system at /tmp/rclone1663228036", Modify Window "1ms" 2021/12/01 05:34:46 DEBUG : b/potato: md5 = 4abdf61a24fc483a880bebcd8e3c8599 OK 2021/12/01 05:34:49 DEBUG : c/non empty space: md5 = 34c55d28f1172a63fea56212a302e815 OK 2021/12/01 05:34:49 DEBUG : d: Making directory 2021/12/01 05:34:51 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-beyemut3qobodab0bifemeh5': Waiting for checks to finish 2021/12/01 05:34:51 DEBUG : c/non empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2021/12/01 05:34:51 DEBUG : c/non empty space: Unchanged skipping 2021/12/01 05:34:51 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-beyemut3qobodab0bifemeh5': Waiting for transfers to finish 2021/12/01 05:34:53 DEBUG : a/potato2: md5 = 4debb951bd44c89d80c941e91cf79466 OK 2021/12/01 05:34:53 INFO : a/potato2: Copied (new) 2021/12/01 05:34:53 ERROR : Encrypted drive 'TestCryptDrive:rclone-test-beyemut3qobodab0bifemeh5': not deleting files as there were IO errors 2021/12/01 05:34:53 ERROR : Encrypted drive 'TestCryptDrive:rclone-test-beyemut3qobodab0bifemeh5': not deleting directories as there were IO errors 2021/12/01 05:34:58 DEBUG : 3i9du405pfogq3ncai6pg7ouio: Rmdir: contains trashed file: "982d3pss7t5pn0il16r2foj31s" 2021/12/01 05:34:58 DEBUG : 32d8ua6196mc1r7qkfog53rkg0: Rmdir: contains trashed file: "2m507n64kafsi59v9q71r281a4" 2021/12/01 05:34:59 DEBUG : 2bsvlrk2ne1lfitm6tttcu0qt8: Rmdir: contains trashed file: "89l8renevh3mji1c8r1p7qn6tg" --- PASS: TestSyncAfterRemovingAFileAndAddingAFileSubDirWithErrors (16.91s) === RUN TestSyncDeleteAfter --- PASS: TestSyncDeleteAfter (0.00s) === RUN TestSyncDeleteDuring run.go:181: Remote "Encrypted drive 'TestCryptDrive:rclone-test-beyemut3qobodab0bifemeh5'", Local "Local file system at /tmp/rclone1663228036", Modify Window "1ms" 2021/12/01 05:35:02 DEBUG : potato: md5 = 78cffa1a93bf5b29662630be74abf823 OK 2021/12/01 05:35:03 DEBUG : empty space: md5 = 212824b7a404a4270e4a76211fa7b869 OK 2021/12/01 05:35:04 DEBUG : Waiting for deletions to finish 2021/12/01 05:35:04 DEBUG : empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2021/12/01 05:35:04 DEBUG : empty space: Unchanged skipping 2021/12/01 05:35:04 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-beyemut3qobodab0bifemeh5': Waiting for checks to finish 2021/12/01 05:35:04 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-beyemut3qobodab0bifemeh5': Waiting for transfers to finish 2021/12/01 05:35:05 INFO : potato: Deleted 2021/12/01 05:35:06 DEBUG : potato2: md5 = 589c8881ff19cf0bcb3450f952f12e2d OK 2021/12/01 05:35:06 INFO : potato2: Copied (new) --- PASS: TestSyncDeleteDuring (7.61s) === RUN TestSyncDeleteBefore run.go:181: Remote "Encrypted drive 'TestCryptDrive:rclone-test-beyemut3qobodab0bifemeh5'", Local "Local file system at /tmp/rclone1663228036", Modify Window "1ms" 2021/12/01 05:35:10 DEBUG : potato: md5 = a992c15110dab9dad4d57981b7dfb394 OK 2021/12/01 05:35:11 DEBUG : empty space: md5 = 99e24c7b1f41142735e7ae1f70320d1e OK 2021/12/01 05:35:11 DEBUG : Waiting for deletions to finish 2021/12/01 05:35:12 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-beyemut3qobodab0bifemeh5': Waiting for checks to finish 2021/12/01 05:35:12 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-beyemut3qobodab0bifemeh5': Waiting for transfers to finish 2021/12/01 05:35:12 INFO : potato: Deleted 2021/12/01 05:35:13 DEBUG : empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2021/12/01 05:35:13 DEBUG : empty space: Unchanged skipping 2021/12/01 05:35:13 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-beyemut3qobodab0bifemeh5': Waiting for checks to finish 2021/12/01 05:35:13 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-beyemut3qobodab0bifemeh5': Waiting for transfers to finish 2021/12/01 05:35:14 DEBUG : potato2: md5 = b688669269eb4a6862da6d610a6e9c8e OK 2021/12/01 05:35:14 INFO : potato2: Copied (new) --- PASS: TestSyncDeleteBefore (8.29s) === RUN TestCopyDeleteBefore run.go:181: Remote "Encrypted drive 'TestCryptDrive:rclone-test-beyemut3qobodab0bifemeh5'", Local "Local file system at /tmp/rclone1663228036", Modify Window "1ms" 2021/12/01 05:35:18 DEBUG : potato: md5 = ba6d6a27f0c7a5dcc8cd9b14885bd2c5 OK 2021/12/01 05:35:18 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-beyemut3qobodab0bifemeh5': Waiting for checks to finish 2021/12/01 05:35:18 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-beyemut3qobodab0bifemeh5': Waiting for transfers to finish 2021/12/01 05:35:20 DEBUG : potato2: md5 = 63f4e41f861e4a2e1c7e2c532de3f8fb OK 2021/12/01 05:35:20 INFO : potato2: Copied (new) --- PASS: TestCopyDeleteBefore (5.77s) === RUN TestSyncWithExclude run.go:181: Remote "Encrypted drive 'TestCryptDrive:rclone-test-beyemut3qobodab0bifemeh5'", Local "Local file system at /tmp/rclone1663228036", Modify Window "1ms" 2021/12/01 05:35:24 DEBUG : potato2: md5 = bf08f62d7d7d450e450d5d1c1654fcd3 OK 2021/12/01 05:35:25 DEBUG : empty space: md5 = 23893b9315ca7f5f8983005a1bfa0364 OK 2021/12/01 05:35:25 DEBUG : enormous: Excluded 2021/12/01 05:35:25 DEBUG : potato2: Excluded 2021/12/01 05:35:26 DEBUG : potato2: Excluded 2021/12/01 05:35:26 DEBUG : empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2021/12/01 05:35:26 DEBUG : empty space: Unchanged skipping 2021/12/01 05:35:26 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-beyemut3qobodab0bifemeh5': Waiting for checks to finish 2021/12/01 05:35:26 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-beyemut3qobodab0bifemeh5': Waiting for transfers to finish 2021/12/01 05:35:26 DEBUG : Waiting for deletions to finish 2021/12/01 05:35:26 INFO : There was nothing to transfer 2021/12/01 05:35:26 DEBUG : enormous: Excluded 2021/12/01 05:35:26 DEBUG : potato2: Excluded 2021/12/01 05:35:26 DEBUG : potato2: Excluded 2021/12/01 05:35:26 DEBUG : empty space: Size and modification time the same (differ by 456.789µs, within tolerance 1ms) 2021/12/01 05:35:26 DEBUG : empty space: Unchanged skipping 2021/12/01 05:35:26 DEBUG : Local file system at /tmp/rclone1663228036: Waiting for checks to finish 2021/12/01 05:35:26 DEBUG : Local file system at /tmp/rclone1663228036: Waiting for transfers to finish 2021/12/01 05:35:26 DEBUG : Waiting for deletions to finish 2021/12/01 05:35:26 INFO : There was nothing to transfer --- PASS: TestSyncWithExclude (6.23s) === RUN TestSyncWithExcludeAndDeleteExcluded run.go:181: Remote "Encrypted drive 'TestCryptDrive:rclone-test-beyemut3qobodab0bifemeh5'", Local "Local file system at /tmp/rclone1663228036", Modify Window "1ms" 2021/12/01 05:35:30 DEBUG : potato2: md5 = 5c7709845644c725616cb6c09c986eff OK 2021/12/01 05:35:32 DEBUG : empty space: md5 = 88b794282c82e09b97e88f6640637990 OK 2021/12/01 05:35:33 DEBUG : enormous: md5 = 56caf19eeb5b81397968f5c08d2bbbf0 OK 2021/12/01 05:35:33 DEBUG : enormous: Excluded 2021/12/01 05:35:33 DEBUG : potato2: Excluded 2021/12/01 05:35:34 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-beyemut3qobodab0bifemeh5': Waiting for checks to finish 2021/12/01 05:35:34 DEBUG : empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2021/12/01 05:35:34 DEBUG : empty space: Unchanged skipping 2021/12/01 05:35:34 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-beyemut3qobodab0bifemeh5': Waiting for transfers to finish 2021/12/01 05:35:34 DEBUG : Waiting for deletions to finish 2021/12/01 05:35:34 INFO : potato2: Deleted 2021/12/01 05:35:34 INFO : enormous: Deleted 2021/12/01 05:35:34 INFO : There was nothing to transfer 2021/12/01 05:35:35 DEBUG : empty space: Size and modification time the same (differ by 456.789µs, within tolerance 1ms) 2021/12/01 05:35:35 DEBUG : Local file system at /tmp/rclone1663228036: Waiting for checks to finish 2021/12/01 05:35:35 DEBUG : empty space: Unchanged skipping 2021/12/01 05:35:35 DEBUG : Local file system at /tmp/rclone1663228036: Waiting for transfers to finish 2021/12/01 05:35:35 DEBUG : Waiting for deletions to finish 2021/12/01 05:35:35 INFO : enormous: Deleted 2021/12/01 05:35:35 INFO : potato2: Deleted 2021/12/01 05:35:35 INFO : There was nothing to transfer --- PASS: TestSyncWithExcludeAndDeleteExcluded (7.98s) === RUN TestSyncWithUpdateOlder run.go:181: Remote "Encrypted drive 'TestCryptDrive:rclone-test-beyemut3qobodab0bifemeh5'", Local "Local file system at /tmp/rclone1663228036", Modify Window "1ms" 2021/12/01 05:35:38 DEBUG : one: md5 = a1cd6e548e61cddfd89e9cfa89b20292 OK 2021/12/01 05:35:39 DEBUG : two: md5 = 6dae76f4c47d3beb7d2980078976160a OK 2021/12/01 05:35:41 DEBUG : three: md5 = 8fca15c00d2dcc3b960d70416274fb3a OK 2021/12/01 05:35:42 DEBUG : four: md5 = e262aa5a19ed496c95758bf812c5f960 OK 2021/12/01 05:35:43 DEBUG : four: Sizes differ (src 4 vs dst 8) 2021/12/01 05:35:43 DEBUG : four: Destination mod time is within 1s of source but files differ, transferring 2021/12/01 05:35:43 DEBUG : three: Sizes identical 2021/12/01 05:35:43 DEBUG : three: Destination mod time is within 1s of source and files identical, skipping 2021/12/01 05:35:43 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-beyemut3qobodab0bifemeh5': Waiting for checks to finish 2021/12/01 05:35:43 DEBUG : one: Destination is newer than source, skipping 2021/12/01 05:35:43 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-beyemut3qobodab0bifemeh5': Waiting for transfers to finish 2021/12/01 05:35:44 DEBUG : two: md5 = 03767281fd0628dcf1f581587e607c49 OK 2021/12/01 05:35:44 INFO : two: Copied (replaced existing) 2021/12/01 05:35:44 DEBUG : four: md5 = 14aad24861adfa97c9322805aa168e19 OK 2021/12/01 05:35:44 INFO : four: Copied (replaced existing) 2021/12/01 05:35:45 DEBUG : five: md5 = b44cceccef56ffc7bcccbfd335fc37db OK 2021/12/01 05:35:45 INFO : five: Copied (new) 2021/12/01 05:35:45 DEBUG : Waiting for deletions to finish sync_test.go:992: Skip test with --checksum as no hashes supported --- PASS: TestSyncWithUpdateOlder (12.65s) === RUN TestSyncWithMaxDuration sync_test.go:1009: Skipping test on non local remote --- SKIP: TestSyncWithMaxDuration (0.00s) === RUN TestSyncWithTrackRenames run.go:181: Remote "Encrypted drive 'TestCryptDrive:rclone-test-beyemut3qobodab0bifemeh5'", Local "Local file system at /tmp/rclone1663228036", Modify Window "1ms" sync_test.go:1058: Can track renames: false 2021/12/01 05:35:49 ERROR : Encrypted drive 'TestCryptDrive:rclone-test-beyemut3qobodab0bifemeh5': Ignoring --track-renames as the source and destination do not have a common hash 2021/12/01 05:35:49 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-beyemut3qobodab0bifemeh5': Waiting for checks to finish 2021/12/01 05:35:49 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-beyemut3qobodab0bifemeh5': Waiting for transfers to finish 2021/12/01 05:35:51 DEBUG : potato: md5 = 2f7f72072ebc4e8a8f264949934da839 OK 2021/12/01 05:35:51 INFO : potato: Copied (new) 2021/12/01 05:35:51 DEBUG : yam: md5 = 5b50c2ce3161cd7f3efea81e45cd1d8b OK 2021/12/01 05:35:51 INFO : yam: Copied (new) 2021/12/01 05:35:51 DEBUG : Waiting for deletions to finish 2021/12/01 05:35:51 ERROR : Encrypted drive 'TestCryptDrive:rclone-test-beyemut3qobodab0bifemeh5': Ignoring --track-renames as the source and destination do not have a common hash 2021/12/01 05:35:52 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-beyemut3qobodab0bifemeh5': Waiting for checks to finish 2021/12/01 05:35:52 DEBUG : potato: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2021/12/01 05:35:52 DEBUG : potato: Unchanged skipping 2021/12/01 05:35:52 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-beyemut3qobodab0bifemeh5': Waiting for transfers to finish 2021/12/01 05:35:53 DEBUG : yaml: md5 = 3119a6a8cbab4b4a7a0dd083030c1d4f OK 2021/12/01 05:35:53 INFO : yaml: Copied (new) 2021/12/01 05:35:53 DEBUG : Waiting for deletions to finish 2021/12/01 05:35:54 INFO : yam: Deleted --- PASS: TestSyncWithTrackRenames (7.14s) === RUN TestParseRenamesStrategyModtime --- PASS: TestParseRenamesStrategyModtime (0.00s) === RUN TestRenamesStrategyModtime --- PASS: TestRenamesStrategyModtime (0.00s) === RUN TestSyncWithTrackRenamesStrategyModtime run.go:181: Remote "Encrypted drive 'TestCryptDrive:rclone-test-beyemut3qobodab0bifemeh5'", Local "Local file system at /tmp/rclone1663228036", Modify Window "1ms" sync_test.go:1127: Can track renames: true 2021/12/01 05:35:56 INFO : Encrypted drive 'TestCryptDrive:rclone-test-beyemut3qobodab0bifemeh5': Making map for --track-renames 2021/12/01 05:35:56 INFO : Encrypted drive 'TestCryptDrive:rclone-test-beyemut3qobodab0bifemeh5': Finished making map for --track-renames 2021/12/01 05:35:56 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-beyemut3qobodab0bifemeh5': Waiting for checks to finish 2021/12/01 05:35:56 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-beyemut3qobodab0bifemeh5': Waiting for renames to finish 2021/12/01 05:35:56 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-beyemut3qobodab0bifemeh5': Waiting for transfers to finish 2021/12/01 05:35:58 DEBUG : yam: md5 = 78b9bdc90804588232818bc827e9045f OK 2021/12/01 05:35:58 INFO : yam: Copied (new) 2021/12/01 05:35:58 DEBUG : potato: md5 = 618b9d058e370a1d746539247bc28edc OK 2021/12/01 05:35:58 INFO : potato: Copied (new) 2021/12/01 05:35:58 DEBUG : Waiting for deletions to finish 2021/12/01 05:35:59 DEBUG : potato: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2021/12/01 05:35:59 DEBUG : potato: Unchanged skipping 2021/12/01 05:35:59 INFO : Encrypted drive 'TestCryptDrive:rclone-test-beyemut3qobodab0bifemeh5': Making map for --track-renames 2021/12/01 05:35:59 INFO : Encrypted drive 'TestCryptDrive:rclone-test-beyemut3qobodab0bifemeh5': Finished making map for --track-renames 2021/12/01 05:35:59 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-beyemut3qobodab0bifemeh5': Waiting for checks to finish 2021/12/01 05:35:59 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-beyemut3qobodab0bifemeh5': Waiting for renames to finish 2021/12/01 05:36:00 INFO : yam: Moved (server-side) to: yaml 2021/12/01 05:36:00 INFO : yaml: Renamed from "yam" 2021/12/01 05:36:00 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-beyemut3qobodab0bifemeh5': Waiting for transfers to finish 2021/12/01 05:36:00 DEBUG : Waiting for deletions to finish 2021/12/01 05:36:00 INFO : There was nothing to transfer --- PASS: TestSyncWithTrackRenamesStrategyModtime (6.02s) === RUN TestSyncWithTrackRenamesStrategyLeaf run.go:181: Remote "Encrypted drive 'TestCryptDrive:rclone-test-beyemut3qobodab0bifemeh5'", Local "Local file system at /tmp/rclone1663228036", Modify Window "1ms" sync_test.go:1163: Can track renames: true 2021/12/01 05:36:02 INFO : Encrypted drive 'TestCryptDrive:rclone-test-beyemut3qobodab0bifemeh5': Making map for --track-renames 2021/12/01 05:36:02 INFO : Encrypted drive 'TestCryptDrive:rclone-test-beyemut3qobodab0bifemeh5': Finished making map for --track-renames 2021/12/01 05:36:02 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-beyemut3qobodab0bifemeh5': Waiting for checks to finish 2021/12/01 05:36:02 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-beyemut3qobodab0bifemeh5': Waiting for renames to finish 2021/12/01 05:36:02 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-beyemut3qobodab0bifemeh5': Waiting for transfers to finish 2021/12/01 05:36:05 DEBUG : sub/yam: md5 = ce4b6c79802abe75b7d94134ef4fdd48 OK 2021/12/01 05:36:05 INFO : sub/yam: Copied (new) 2021/12/01 05:36:05 DEBUG : potato: md5 = f6153ccb5b7e0f3b8d54880fc4f086b4 OK 2021/12/01 05:36:05 INFO : potato: Copied (new) 2021/12/01 05:36:05 DEBUG : Waiting for deletions to finish 2021/12/01 05:36:06 DEBUG : potato: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2021/12/01 05:36:06 DEBUG : potato: Unchanged skipping 2021/12/01 05:36:07 INFO : Encrypted drive 'TestCryptDrive:rclone-test-beyemut3qobodab0bifemeh5': Making map for --track-renames 2021/12/01 05:36:07 INFO : Encrypted drive 'TestCryptDrive:rclone-test-beyemut3qobodab0bifemeh5': Finished making map for --track-renames 2021/12/01 05:36:07 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-beyemut3qobodab0bifemeh5': Waiting for checks to finish 2021/12/01 05:36:07 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-beyemut3qobodab0bifemeh5': Waiting for renames to finish 2021/12/01 05:36:08 INFO : sub/yam: Moved (server-side) to: yam 2021/12/01 05:36:08 INFO : yam: Renamed from "sub/yam" 2021/12/01 05:36:08 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-beyemut3qobodab0bifemeh5': Waiting for transfers to finish 2021/12/01 05:36:08 DEBUG : Waiting for deletions to finish 2021/12/01 05:36:08 INFO : There was nothing to transfer --- PASS: TestSyncWithTrackRenamesStrategyLeaf (9.47s) === RUN TestMoveWithDeleteEmptySrcDirs run.go:181: Remote "Encrypted drive 'TestCryptDrive:rclone-test-beyemut3qobodab0bifemeh5'", Local "Local file system at /tmp/rclone1663228036", Modify Window "1ms" 2021/12/01 05:36:12 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-beyemut3qobodab0bifemeh5': Waiting for checks to finish 2021/12/01 05:36:12 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-beyemut3qobodab0bifemeh5': Waiting for transfers to finish 2021/12/01 05:36:14 DEBUG : sub dir/hello world: md5 = 79691e215f995a316eca8c8899ac4efd OK 2021/12/01 05:36:14 INFO : sub dir/hello world: Copied (new) 2021/12/01 05:36:14 INFO : sub dir/hello world: Deleted 2021/12/01 05:36:17 DEBUG : nested/sub dir/file: md5 = 4d487a8824b28b5651893ab8170b56b4 OK 2021/12/01 05:36:17 INFO : nested/sub dir/file: Copied (new) 2021/12/01 05:36:17 INFO : nested/sub dir/file: Deleted 2021/12/01 05:36:17 INFO : sub dir: Removing directory 2021/12/01 05:36:17 INFO : nested/sub dir: Removing directory 2021/12/01 05:36:17 INFO : nested: Removing directory 2021/12/01 05:36:17 DEBUG : Local file system at /tmp/rclone1663228036: deleted 3 directories 2021/12/01 05:36:20 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" 2021/12/01 05:36:21 DEBUG : 37qp6d1gohacv723ij3brofbu8/14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "ftp4kuv8se7tqduu6pmmcvjsmk" 2021/12/01 05:36:22 DEBUG : 37qp6d1gohacv723ij3brofbu8: Rmdir: contains trashed file: "14begaa36ih249fgrnfk6nulg0" --- PASS: TestMoveWithDeleteEmptySrcDirs (11.69s) === RUN TestMoveWithoutDeleteEmptySrcDirs run.go:181: Remote "Encrypted drive 'TestCryptDrive:rclone-test-beyemut3qobodab0bifemeh5'", Local "Local file system at /tmp/rclone1663228036", Modify Window "1ms" 2021/12/01 05:36:23 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-beyemut3qobodab0bifemeh5': Waiting for checks to finish 2021/12/01 05:36:23 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-beyemut3qobodab0bifemeh5': Waiting for transfers to finish 2021/12/01 05:36:26 DEBUG : sub dir/hello world: md5 = fccda2bbbc6cddcf41c6a182adddd68d OK 2021/12/01 05:36:26 INFO : sub dir/hello world: Copied (new) 2021/12/01 05:36:26 INFO : sub dir/hello world: Deleted 2021/12/01 05:36:28 DEBUG : nested/sub dir/file: md5 = 18b7855c391fee47bf62414e0444a7e0 OK 2021/12/01 05:36:28 INFO : nested/sub dir/file: Copied (new) 2021/12/01 05:36:28 INFO : nested/sub dir/file: Deleted 2021/12/01 05:36:32 DEBUG : 14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "8j9gk4b744l35einofkqsr2mvo" 2021/12/01 05:36:33 DEBUG : 37qp6d1gohacv723ij3brofbu8/14begaa36ih249fgrnfk6nulg0: Rmdir: contains trashed file: "ftp4kuv8se7tqduu6pmmcvjsmk" 2021/12/01 05:36:34 DEBUG : 37qp6d1gohacv723ij3brofbu8: Rmdir: contains trashed file: "14begaa36ih249fgrnfk6nulg0" --- PASS: TestMoveWithoutDeleteEmptySrcDirs (11.54s) === RUN TestMoveWithIgnoreExisting run.go:181: Remote "Encrypted drive 'TestCryptDrive:rclone-test-beyemut3qobodab0bifemeh5'", Local "Local file system at /tmp/rclone1663228036", Modify Window "1ms" 2021/12/01 05:36:35 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-beyemut3qobodab0bifemeh5': Waiting for checks to finish 2021/12/01 05:36:35 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-beyemut3qobodab0bifemeh5': Waiting for transfers to finish 2021/12/01 05:36:37 DEBUG : existing: md5 = b5394f3fe88b088ebedf8ff8cefc9031 OK 2021/12/01 05:36:37 INFO : existing: Copied (new) 2021/12/01 05:36:37 INFO : existing: Deleted 2021/12/01 05:36:37 DEBUG : existing-b: md5 = f37327be010add64abb7b6c442bfa0bf OK 2021/12/01 05:36:37 INFO : existing-b: Copied (new) 2021/12/01 05:36:37 INFO : existing-b: Deleted 2021/12/01 05:36:37 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-beyemut3qobodab0bifemeh5': Waiting for checks to finish 2021/12/01 05:36:37 DEBUG : existing: Destination exists, skipping 2021/12/01 05:36:37 DEBUG : existing: Not removing source file as destination file exists and --ignore-existing is set 2021/12/01 05:36:37 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-beyemut3qobodab0bifemeh5': Waiting for transfers to finish 2021/12/01 05:36:37 INFO : There was nothing to transfer --- PASS: TestMoveWithIgnoreExisting (4.69s) === RUN TestServerSideMove run.go:181: Remote "Encrypted drive 'TestCryptDrive:rclone-test-beyemut3qobodab0bifemeh5'", Local "Local file system at /tmp/rclone1663228036", Modify Window "1ms" 2021/12/01 05:36:39 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-tawarih8vexatot9miwudis8" 2021/12/01 05:36:40 DEBUG : Creating backend with remote "TestDrive:crypt/pn82h8k9a67gp4nml8kn2a0t839p81hr73a954snrm6kp6pggb422tm9ujgmm6dou7vvi1ulm2qpg" 2021/12/01 05:36:42 DEBUG : potato2: md5 = 81559cbe3ffd048da2a25406a18755c2 OK 2021/12/01 05:36:44 DEBUG : empty space: md5 = 2c68db7572332954691ed503fee63a7a OK 2021/12/01 05:36:45 DEBUG : potato3: md5 = 50875404cdf2ae015544dfcde0b0fe99 OK sync_test.go:1215: Server side move (if possible) Encrypted drive 'TestCryptDrive:rclone-test-beyemut3qobodab0bifemeh5' -> Encrypted drive 'TestCryptDrive:rclone-test-tawarih8vexatot9miwudis8' 2021/12/01 05:36:48 DEBUG : empty space: md5 = 2e6a1c8367ef60bed95c746d902d6795 OK 2021/12/01 05:36:50 DEBUG : potato3: md5 = ceb0d61c288c31846d16dba6cc91f8f4 OK 2021/12/01 05:36:50 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tawarih8vexatot9miwudis8': Using server-side directory move 2021/12/01 05:36:50 INFO : Encrypted drive 'TestCryptDrive:rclone-test-tawarih8vexatot9miwudis8': Server side directory move failed - fallback to file moves: can't copy directory - destination already exists 2021/12/01 05:36:52 DEBUG : empty space: Size and modification time the same (differ by 0s, within tolerance 1ms) 2021/12/01 05:36:52 DEBUG : empty space: Unchanged skipping 2021/12/01 05:36:52 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tawarih8vexatot9miwudis8': Waiting for checks to finish 2021/12/01 05:36:52 DEBUG : potato3: Sizes differ (src 68 vs dst 60) 2021/12/01 05:36:53 INFO : empty space: Deleted 2021/12/01 05:36:53 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tawarih8vexatot9miwudis8': Waiting for transfers to finish 2021/12/01 05:36:53 INFO : potato3: Deleted 2021/12/01 05:36:53 INFO : potato2: Moved (server-side) 2021/12/01 05:36:54 INFO : potato3: Moved (server-side) 2021/12/01 05:36:54 INFO : There was nothing to transfer 2021/12/01 05:36:54 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-qayuyoz5konegig3sonodeg3" 2021/12/01 05:36:55 DEBUG : Creating backend with remote "TestDrive:crypt/msg0509nu44eb1k1i7g8vds678qnaskfem3e3t5vabgh5a20macdd0pui586l84s6eov70v28evka" 2021/12/01 05:36:56 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-qayuyoz5konegig3sonodeg3': Using server-side directory move 2021/12/01 05:36:57 INFO : Encrypted drive 'TestCryptDrive:rclone-test-qayuyoz5konegig3sonodeg3': Server side directory move succeeded 2021/12/01 05:36:58 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-qayuyoz5konegig3sonodeg3': Purge remote 2021/12/01 05:36:58 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tawarih8vexatot9miwudis8': Purge remote 2021/12/01 05:36:59 purge failed: directory not found --- PASS: TestServerSideMove (19.58s) === RUN TestServerSideMoveWithFilter run.go:181: Remote "Encrypted drive 'TestCryptDrive:rclone-test-beyemut3qobodab0bifemeh5'", Local "Local file system at /tmp/rclone1663228036", Modify Window "1ms" 2021/12/01 05:36:59 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-nosidum7supujec3lajezah9" 2021/12/01 05:36:59 DEBUG : Creating backend with remote "TestDrive:crypt/btomtvlqtg2v54f6drcijvmi4c8ie4fitsi28g9i800628haleutmv2e18lfalq60cqkbolqa0c4k" 2021/12/01 05:37:02 DEBUG : potato2: md5 = f797049fec37f7ec4f096d8a4eef3d5c OK 2021/12/01 05:37:03 DEBUG : empty space: md5 = 1fe6d648fc62cabef89098a19ecac9dd OK 2021/12/01 05:37:05 DEBUG : potato3: md5 = ade13f03bbb819f804bca88440caf675 OK sync_test.go:1215: Server side move (if possible) Encrypted drive 'TestCryptDrive:rclone-test-beyemut3qobodab0bifemeh5' -> Encrypted drive 'TestCryptDrive:rclone-test-nosidum7supujec3lajezah9' 2021/12/01 05:37:08 DEBUG : empty space: md5 = d289ff0dbf9451caa77b8471dcb70b2b OK 2021/12/01 05:37:09 DEBUG : potato3: md5 = 3ddeef6cf9fcc8805299c109dc89e3b3 OK 2021/12/01 05:37:10 DEBUG : empty space: Excluded 2021/12/01 05:37:10 DEBUG : empty space: Excluded 2021/12/01 05:37:10 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-nosidum7supujec3lajezah9': Waiting for checks to finish 2021/12/01 05:37:10 DEBUG : potato3: Sizes differ (src 68 vs dst 60) 2021/12/01 05:37:10 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-nosidum7supujec3lajezah9': Waiting for transfers to finish 2021/12/01 05:37:11 INFO : potato3: Deleted 2021/12/01 05:37:11 INFO : potato2: Moved (server-side) 2021/12/01 05:37:12 INFO : potato3: Moved (server-side) 2021/12/01 05:37:12 INFO : There was nothing to transfer 2021/12/01 05:37:12 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-tiyonac5cewolab9hasoley8" 2021/12/01 05:37:12 DEBUG : Creating backend with remote "TestDrive:crypt/95o8q5j2re8or2t281ou64dngioniblrde9b9uqq5su08veimhu2lb6uordaghnugebiogqh8dfv6" 2021/12/01 05:37:14 DEBUG : empty space: Excluded 2021/12/01 05:37:14 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tiyonac5cewolab9hasoley8': Waiting for checks to finish 2021/12/01 05:37:14 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tiyonac5cewolab9hasoley8': Waiting for transfers to finish 2021/12/01 05:37:16 INFO : potato2: Moved (server-side) 2021/12/01 05:37:16 INFO : potato3: Moved (server-side) 2021/12/01 05:37:16 INFO : There was nothing to transfer 2021/12/01 05:37:17 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-tiyonac5cewolab9hasoley8': Purge remote 2021/12/01 05:37:18 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-nosidum7supujec3lajezah9': Purge remote --- PASS: TestServerSideMoveWithFilter (20.45s) === RUN TestServerSideMoveDeleteEmptySourceDirs run.go:181: Remote "Encrypted drive 'TestCryptDrive:rclone-test-beyemut3qobodab0bifemeh5'", Local "Local file system at /tmp/rclone1663228036", Modify Window "1ms" 2021/12/01 05:37:19 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-loginas8terafal0jeguzan9" 2021/12/01 05:37:20 DEBUG : Creating backend with remote "TestDrive:crypt/ch16ner3m25m18bf9lippab2kvldb7hgr5gs619penpehbvmfi2fm7k0b8u3mc85l355iv9mve92o" 2021/12/01 05:37:22 DEBUG : potato2: md5 = 682138c326bc058d88669288b2a7e058 OK 2021/12/01 05:37:24 DEBUG : empty space: md5 = 92cff8a6384811f4d367c5b1f0d4bb82 OK 2021/12/01 05:37:26 DEBUG : potato3: md5 = f2ff4b8857a55ece2e8f3faf38fdaa00 OK 2021/12/01 05:37:26 DEBUG : tomatoDir: Making directory sync_test.go:1215: Server side move (if possible) Encrypted drive 'TestCryptDrive:rclone-test-beyemut3qobodab0bifemeh5' -> Encrypted drive 'TestCryptDrive:rclone-test-loginas8terafal0jeguzan9' 2021/12/01 05:37:30 DEBUG : empty space: md5 = 2093c200b85bd880ce6dfbf1f0ff2f72 OK 2021/12/01 05:37:32 DEBUG : potato3: md5 = f93a4ea8145d0e6e30f0174af44a693b OK 2021/12/01 05:37:32 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-loginas8terafal0jeguzan9': Using server-side directory move 2021/12/01 05:37:32 INFO : Encrypted drive 'TestCryptDrive:rclone-test-loginas8terafal0jeguzan9': Server side directory move failed - fallback to file moves: can't copy directory - destination already exists 2021/12/01 05:37:32 DEBUG : empty space: Size and modification time the same (differ by 0s, within tolerance 1ms) 2021/12/01 05:37:32 DEBUG : empty space: Unchanged skipping 2021/12/01 05:37:32 DEBUG : potato3: Sizes differ (src 68 vs dst 60) 2021/12/01 05:37:33 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-loginas8terafal0jeguzan9': Waiting for checks to finish 2021/12/01 05:37:33 INFO : empty space: Deleted 2021/12/01 05:37:33 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-loginas8terafal0jeguzan9': Waiting for transfers to finish 2021/12/01 05:37:33 INFO : potato3: Deleted 2021/12/01 05:37:33 INFO : potato2: Moved (server-side) 2021/12/01 05:37:34 INFO : potato3: Moved (server-side) 2021/12/01 05:37:34 INFO : tomatoDir: Removing directory 2021/12/01 05:37:35 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-beyemut3qobodab0bifemeh5': deleted 1 directories 2021/12/01 05:37:35 INFO : There was nothing to transfer 2021/12/01 05:37:36 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-haworow7rikelax6pitucaf3" 2021/12/01 05:37:36 DEBUG : Creating backend with remote "TestDrive:crypt/if58n69acevoksv3c6sd789bqkm13easacv690sdk15mor2gr2732a0ils1k3qoqd5g86miebhp1c" 2021/12/01 05:37:37 DEBUG : tomatoDir: Making directory 2021/12/01 05:37:38 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-haworow7rikelax6pitucaf3': Using server-side directory move 2021/12/01 05:37:39 INFO : Encrypted drive 'TestCryptDrive:rclone-test-haworow7rikelax6pitucaf3': Server side directory move succeeded 2021/12/01 05:37:41 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-haworow7rikelax6pitucaf3': Purge remote 2021/12/01 05:37:41 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-loginas8terafal0jeguzan9': Purge remote 2021/12/01 05:37:42 purge failed: directory not found --- PASS: TestServerSideMoveDeleteEmptySourceDirs (22.54s) === RUN TestServerSideMoveOverlap run.go:181: Remote "Encrypted drive 'TestCryptDrive:rclone-test-beyemut3qobodab0bifemeh5'", Local "Local file system at /tmp/rclone1663228036", Modify Window "1ms" sync_test.go:1399: Skipping test as remote supports DirMove --- SKIP: TestServerSideMoveOverlap (0.52s) === RUN TestSyncOverlap run.go:181: Remote "Encrypted drive 'TestCryptDrive:rclone-test-beyemut3qobodab0bifemeh5'", Local "Local file system at /tmp/rclone1663228036", Modify Window "1ms" 2021/12/01 05:37:43 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-beyemut3qobodab0bifemeh5/rclone-sync-test" 2021/12/01 05:37:43 DEBUG : Creating backend with remote "TestDrive:crypt/arh3eumf1lvqc7k624qhttajs1a59mn77ptb70pl7o7pgr4hoe7n4slnp15daij7ucl94ssdmkc00/i7355aa0sb89uagn75vfjqr6s3e3e1h2et8in57abn1fe8qfego0" --- PASS: TestSyncOverlap (2.46s) === RUN TestSyncCompareDest run.go:181: Remote "Encrypted drive 'TestCryptDrive:rclone-test-beyemut3qobodab0bifemeh5'", Local "Local file system at /tmp/rclone1663228036", Modify Window "1ms" 2021/12/01 05:37:45 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-beyemut3qobodab0bifemeh5/dst" 2021/12/01 05:37:45 DEBUG : Creating backend with remote "TestDrive:crypt/arh3eumf1lvqc7k624qhttajs1a59mn77ptb70pl7o7pgr4hoe7n4slnp15daij7ucl94ssdmkc00/31u3jie661vd5p8j7rtc3hgbh0" 2021/12/01 05:37:47 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-beyemut3qobodab0bifemeh5/CompareDest" 2021/12/01 05:37:47 DEBUG : Creating backend with remote "TestDrive:crypt/arh3eumf1lvqc7k624qhttajs1a59mn77ptb70pl7o7pgr4hoe7n4slnp15daij7ucl94ssdmkc00/gveqi14airsml4bgu7krj116o8" 2021/12/01 05:37:50 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-beyemut3qobodab0bifemeh5/dst': Waiting for checks to finish 2021/12/01 05:37:50 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-beyemut3qobodab0bifemeh5/dst': Waiting for transfers to finish 2021/12/01 05:37:52 DEBUG : one: md5 = 00dc94f34ba2538c92d201fd845303a1 OK 2021/12/01 05:37:52 INFO : one: Copied (new) 2021/12/01 05:37:52 DEBUG : Waiting for deletions to finish 2021/12/01 05:37:54 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-beyemut3qobodab0bifemeh5/dst': Waiting for checks to finish 2021/12/01 05:37:54 DEBUG : one: Sizes differ (src 5 vs dst 3) 2021/12/01 05:37:54 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-beyemut3qobodab0bifemeh5/dst': Waiting for transfers to finish 2021/12/01 05:37:55 DEBUG : one: md5 = ab00954fa5be4d8bf3f305bd96f8dfdc OK 2021/12/01 05:37:55 INFO : one: Copied (replaced existing) 2021/12/01 05:37:55 DEBUG : Waiting for deletions to finish 2021/12/01 05:37:58 DEBUG : dst/one: md5 = 84e28a9b37f80c63268fcf092e3c4dc2 OK 2021/12/01 05:38:00 DEBUG : CompareDest/one: md5 = c72262b75f74ec187773f0ce1a8fd74a OK 2021/12/01 05:38:01 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-beyemut3qobodab0bifemeh5/dst': Waiting for checks to finish 2021/12/01 05:38:02 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2021/12/01 05:38:02 DEBUG : one: Destination found in --compare-dest, skipping 2021/12/01 05:38:02 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-beyemut3qobodab0bifemeh5/dst': Waiting for transfers to finish 2021/12/01 05:38:02 DEBUG : Waiting for deletions to finish 2021/12/01 05:38:02 INFO : There was nothing to transfer 2021/12/01 05:38:04 DEBUG : CompareDest/two: md5 = e687299c3c025bcd94c7c5b49ee0026f OK 2021/12/01 05:38:05 DEBUG : two: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2021/12/01 05:38:05 DEBUG : two: Destination found in --compare-dest, skipping 2021/12/01 05:38:05 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-beyemut3qobodab0bifemeh5/dst': Waiting for checks to finish 2021/12/01 05:38:06 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2021/12/01 05:38:06 DEBUG : one: Destination found in --compare-dest, skipping 2021/12/01 05:38:06 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-beyemut3qobodab0bifemeh5/dst': Waiting for transfers to finish 2021/12/01 05:38:06 DEBUG : Waiting for deletions to finish 2021/12/01 05:38:06 INFO : There was nothing to transfer 2021/12/01 05:38:07 DEBUG : two: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2021/12/01 05:38:07 DEBUG : two: Destination found in --compare-dest, skipping 2021/12/01 05:38:07 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-beyemut3qobodab0bifemeh5/dst': Waiting for checks to finish 2021/12/01 05:38:07 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2021/12/01 05:38:07 DEBUG : one: Destination found in --compare-dest, skipping 2021/12/01 05:38:07 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-beyemut3qobodab0bifemeh5/dst': Waiting for transfers to finish 2021/12/01 05:38:07 DEBUG : Waiting for deletions to finish 2021/12/01 05:38:07 INFO : There was nothing to transfer sync_test.go:1543: No hash on uploaded file so skipping compare timestamp test 2021/12/01 05:38:09 DEBUG : two: Sizes differ (src 5 vs dst 3) 2021/12/01 05:38:09 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-beyemut3qobodab0bifemeh5/dst': Waiting for checks to finish 2021/12/01 05:38:09 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2021/12/01 05:38:09 DEBUG : one: Destination found in --compare-dest, skipping 2021/12/01 05:38:09 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-beyemut3qobodab0bifemeh5/dst': Waiting for transfers to finish 2021/12/01 05:38:11 DEBUG : two: md5 = c90360d3ad968d09d136182d4796ed90 OK 2021/12/01 05:38:11 INFO : two: Copied (new) 2021/12/01 05:38:11 DEBUG : Waiting for deletions to finish 2021/12/01 05:38:15 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k" 2021/12/01 05:38:15 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" 2021/12/01 05:38:16 DEBUG : gveqi14airsml4bgu7krj116o8: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" 2021/12/01 05:38:16 DEBUG : gveqi14airsml4bgu7krj116o8: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k" --- PASS: TestSyncCompareDest (31.82s) === RUN TestSyncMultipleCompareDest run.go:181: Remote "Encrypted drive 'TestCryptDrive:rclone-test-beyemut3qobodab0bifemeh5'", Local "Local file system at /tmp/rclone1663228036", Modify Window "1ms" 2021/12/01 05:38:20 DEBUG : pre-dest1/1: md5 = 9c1b346546d5ca4384986c242de35ca4 OK 2021/12/01 05:38:22 DEBUG : pre-dest2/2: md5 = 5a1540469fe643309cab1a56f400b6e2 OK 2021/12/01 05:38:23 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-beyemut3qobodab0bifemeh5/dest" 2021/12/01 05:38:23 DEBUG : Creating backend with remote "TestDrive:crypt/arh3eumf1lvqc7k624qhttajs1a59mn77ptb70pl7o7pgr4hoe7n4slnp15daij7ucl94ssdmkc00/rg03c1jvnehrrc617i0lnqjddc" 2021/12/01 05:38:25 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-beyemut3qobodab0bifemeh5/pre-dest1" 2021/12/01 05:38:25 DEBUG : Creating backend with remote "TestDrive:crypt/arh3eumf1lvqc7k624qhttajs1a59mn77ptb70pl7o7pgr4hoe7n4slnp15daij7ucl94ssdmkc00/bbnblvh6k061ssopqrp18kd7gc" 2021/12/01 05:38:26 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-beyemut3qobodab0bifemeh5/pre-dest2" 2021/12/01 05:38:26 DEBUG : Creating backend with remote "TestDrive:crypt/arh3eumf1lvqc7k624qhttajs1a59mn77ptb70pl7o7pgr4hoe7n4slnp15daij7ucl94ssdmkc00/dgicm1h6b5ejvlltm8eeif0bnk" 2021/12/01 05:38:27 DEBUG : 1: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2021/12/01 05:38:27 DEBUG : 1: Destination found in --compare-dest, skipping 2021/12/01 05:38:28 DEBUG : 2: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2021/12/01 05:38:28 DEBUG : 2: Destination found in --compare-dest, skipping 2021/12/01 05:38:28 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-beyemut3qobodab0bifemeh5/dest': Waiting for checks to finish 2021/12/01 05:38:28 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-beyemut3qobodab0bifemeh5/dest': Waiting for transfers to finish 2021/12/01 05:38:31 DEBUG : 3: md5 = 7001256ce9584339703ba7b6558e021e OK 2021/12/01 05:38:31 INFO : 3: Copied (new) 2021/12/01 05:38:31 DEBUG : Waiting for deletions to finish 2021/12/01 05:38:37 DEBUG : dgicm1h6b5ejvlltm8eeif0bnk: Rmdir: contains trashed file: "1ghu8geql9vrl726n32nrf65bc" 2021/12/01 05:38:38 DEBUG : bbnblvh6k061ssopqrp18kd7gc: Rmdir: contains trashed file: "skbfko3oil7es0lj68ob574sro" 2021/12/01 05:38:39 DEBUG : rg03c1jvnehrrc617i0lnqjddc: Rmdir: contains trashed file: "g072p7hmjchlnj0gibe64c1epg" --- PASS: TestSyncMultipleCompareDest (23.16s) === RUN TestSyncCopyDest run.go:181: Remote "Encrypted drive 'TestCryptDrive:rclone-test-beyemut3qobodab0bifemeh5'", Local "Local file system at /tmp/rclone1663228036", Modify Window "1ms" 2021/12/01 05:38:40 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-beyemut3qobodab0bifemeh5/dst" 2021/12/01 05:38:40 DEBUG : Creating backend with remote "TestDrive:crypt/arh3eumf1lvqc7k624qhttajs1a59mn77ptb70pl7o7pgr4hoe7n4slnp15daij7ucl94ssdmkc00/31u3jie661vd5p8j7rtc3hgbh0" 2021/12/01 05:38:42 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-beyemut3qobodab0bifemeh5/CopyDest" 2021/12/01 05:38:42 DEBUG : Creating backend with remote "TestDrive:crypt/arh3eumf1lvqc7k624qhttajs1a59mn77ptb70pl7o7pgr4hoe7n4slnp15daij7ucl94ssdmkc00/d09o6po3f7bm6ce32vdgs8h9ls" 2021/12/01 05:38:44 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-beyemut3qobodab0bifemeh5/dst': Waiting for checks to finish 2021/12/01 05:38:44 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-beyemut3qobodab0bifemeh5/dst': Waiting for transfers to finish 2021/12/01 05:38:47 DEBUG : one: md5 = fab67344d34400e14b412904fa469d27 OK 2021/12/01 05:38:47 INFO : one: Copied (new) 2021/12/01 05:38:47 DEBUG : Waiting for deletions to finish 2021/12/01 05:38:49 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-beyemut3qobodab0bifemeh5/dst': Waiting for checks to finish 2021/12/01 05:38:49 DEBUG : one: Sizes differ (src 5 vs dst 3) 2021/12/01 05:38:49 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-beyemut3qobodab0bifemeh5/dst': Waiting for transfers to finish 2021/12/01 05:38:50 DEBUG : one: md5 = 7a510317eb7c064aad2fa30e786256b3 OK 2021/12/01 05:38:50 INFO : one: Copied (replaced existing) 2021/12/01 05:38:50 DEBUG : Waiting for deletions to finish 2021/12/01 05:38:52 DEBUG : dst/one: md5 = 539573d476036278623ac0864fa129d0 OK 2021/12/01 05:38:55 DEBUG : CopyDest/one: md5 = 1aad96ed07352989daac0459bbe7ce44 OK 2021/12/01 05:38:55 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-beyemut3qobodab0bifemeh5/BackupDir" 2021/12/01 05:38:55 DEBUG : Creating backend with remote "TestDrive:crypt/arh3eumf1lvqc7k624qhttajs1a59mn77ptb70pl7o7pgr4hoe7n4slnp15daij7ucl94ssdmkc00/s6dbk3lfi7c9kfvo6j7bla9m0g" 2021/12/01 05:38:57 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-beyemut3qobodab0bifemeh5/dst': Waiting for checks to finish 2021/12/01 05:38:58 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2021/12/01 05:38:58 DEBUG : one: Sizes differ (src 5 vs dst 3) 2021/12/01 05:39:00 INFO : one: Moved (server-side) 2021/12/01 05:39:02 INFO : one: Copied (server-side copy) 2021/12/01 05:39:02 DEBUG : one: Destination found in --copy-dest, using server-side copy 2021/12/01 05:39:02 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-beyemut3qobodab0bifemeh5/dst': Waiting for transfers to finish 2021/12/01 05:39:02 DEBUG : Waiting for deletions to finish 2021/12/01 05:39:04 DEBUG : CopyDest/two: md5 = 736b85e933b7ae3bdde85ad5035ed49d OK 2021/12/01 05:39:05 DEBUG : two: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2021/12/01 05:39:07 INFO : two: Copied (server-side copy) 2021/12/01 05:39:07 DEBUG : two: Destination found in --copy-dest, using server-side copy 2021/12/01 05:39:07 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-beyemut3qobodab0bifemeh5/dst': Waiting for checks to finish 2021/12/01 05:39:07 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2021/12/01 05:39:07 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2021/12/01 05:39:07 DEBUG : one: Unchanged skipping 2021/12/01 05:39:07 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-beyemut3qobodab0bifemeh5/dst': Waiting for transfers to finish 2021/12/01 05:39:07 DEBUG : Waiting for deletions to finish 2021/12/01 05:39:08 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-beyemut3qobodab0bifemeh5/dst': Waiting for checks to finish 2021/12/01 05:39:08 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2021/12/01 05:39:08 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2021/12/01 05:39:08 DEBUG : one: Unchanged skipping 2021/12/01 05:39:09 DEBUG : two: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2021/12/01 05:39:09 DEBUG : two: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2021/12/01 05:39:09 DEBUG : two: Unchanged skipping 2021/12/01 05:39:09 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-beyemut3qobodab0bifemeh5/dst': Waiting for transfers to finish 2021/12/01 05:39:09 DEBUG : Waiting for deletions to finish 2021/12/01 05:39:09 INFO : There was nothing to transfer 2021/12/01 05:39:11 DEBUG : CopyDest/three: md5 = fdb213ba548d8e70ac9985aecc940237 OK 2021/12/01 05:39:12 DEBUG : three: Sizes differ (src 7 vs dst 5) 2021/12/01 05:39:12 DEBUG : three: Destination not found in --copy-dest 2021/12/01 05:39:12 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-beyemut3qobodab0bifemeh5/dst': Waiting for checks to finish 2021/12/01 05:39:12 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2021/12/01 05:39:12 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2021/12/01 05:39:12 DEBUG : one: Unchanged skipping 2021/12/01 05:39:12 DEBUG : two: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2021/12/01 05:39:12 DEBUG : two: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2021/12/01 05:39:12 DEBUG : two: Unchanged skipping 2021/12/01 05:39:12 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-beyemut3qobodab0bifemeh5/dst': Waiting for transfers to finish 2021/12/01 05:39:14 DEBUG : three: md5 = e941eaadac68b4c9b912a5de7e008d73 OK 2021/12/01 05:39:14 INFO : three: Copied (new) 2021/12/01 05:39:14 DEBUG : Waiting for deletions to finish 2021/12/01 05:39:20 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "b6jdmn2b1adrhc8vikh7edr9os" 2021/12/01 05:39:20 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" 2021/12/01 05:39:20 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k" 2021/12/01 05:39:21 DEBUG : d09o6po3f7bm6ce32vdgs8h9ls: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" 2021/12/01 05:39:21 DEBUG : d09o6po3f7bm6ce32vdgs8h9ls: Rmdir: contains trashed file: "b6jdmn2b1adrhc8vikh7edr9os" 2021/12/01 05:39:21 DEBUG : d09o6po3f7bm6ce32vdgs8h9ls: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k" 2021/12/01 05:39:22 DEBUG : s6dbk3lfi7c9kfvo6j7bla9m0g: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" --- PASS: TestSyncCopyDest (43.00s) === RUN TestSyncBackupDir run.go:181: Remote "Encrypted drive 'TestCryptDrive:rclone-test-beyemut3qobodab0bifemeh5'", Local "Local file system at /tmp/rclone1663228036", Modify Window "1ms" 2021/12/01 05:39:26 DEBUG : dst/one: md5 = e06abd8739601e89d5fc5781d0b579cc OK 2021/12/01 05:39:27 DEBUG : dst/two: md5 = 6dd542e4f4a18e80aecfaa9f817af5e4 OK 2021/12/01 05:39:29 DEBUG : dst/three.txt: md5 = 3c2fda636296dce5504bae95dc9b870f OK 2021/12/01 05:39:29 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-beyemut3qobodab0bifemeh5/dst" 2021/12/01 05:39:29 DEBUG : Creating backend with remote "TestDrive:crypt/arh3eumf1lvqc7k624qhttajs1a59mn77ptb70pl7o7pgr4hoe7n4slnp15daij7ucl94ssdmkc00/31u3jie661vd5p8j7rtc3hgbh0" 2021/12/01 05:39:30 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-beyemut3qobodab0bifemeh5/backup" 2021/12/01 05:39:30 DEBUG : Creating backend with remote "TestDrive:crypt/arh3eumf1lvqc7k624qhttajs1a59mn77ptb70pl7o7pgr4hoe7n4slnp15daij7ucl94ssdmkc00/1nrff024r7pq65ecp72fc28jb0" 2021/12/01 05:39:33 DEBUG : one: Sizes differ (src 4 vs dst 3) 2021/12/01 05:39:33 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2021/12/01 05:39:33 DEBUG : two: Unchanged skipping 2021/12/01 05:39:33 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-beyemut3qobodab0bifemeh5/dst': Waiting for checks to finish 2021/12/01 05:39:35 INFO : one: Moved (server-side) 2021/12/01 05:39:35 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-beyemut3qobodab0bifemeh5/dst': Waiting for transfers to finish 2021/12/01 05:39:36 DEBUG : one: md5 = afdceb4b663fad43eb90f688fb591bec OK 2021/12/01 05:39:36 INFO : one: Copied (new) 2021/12/01 05:39:36 DEBUG : Waiting for deletions to finish 2021/12/01 05:39:38 INFO : three.txt: Moved (server-side) 2021/12/01 05:39:38 INFO : three.txt: Moved into backup dir 2021/12/01 05:39:40 DEBUG : dst/three.txt: md5 = c5e407c6663ba5f1ab6ac3c43ab1e3ff OK 2021/12/01 05:39:41 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-beyemut3qobodab0bifemeh5/dst': Waiting for checks to finish 2021/12/01 05:39:41 DEBUG : one: Sizes differ (src 5 vs dst 4) 2021/12/01 05:39:41 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2021/12/01 05:39:41 DEBUG : two: Unchanged skipping 2021/12/01 05:39:42 INFO : one: Deleted 2021/12/01 05:39:43 INFO : one: Moved (server-side) 2021/12/01 05:39:43 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-beyemut3qobodab0bifemeh5/dst': Waiting for transfers to finish 2021/12/01 05:39:44 DEBUG : one: md5 = 18735c5e8391caeb68ce044779a5c0ba OK 2021/12/01 05:39:44 INFO : one: Copied (new) 2021/12/01 05:39:44 DEBUG : Waiting for deletions to finish 2021/12/01 05:39:45 INFO : three.txt: Deleted 2021/12/01 05:39:46 INFO : three.txt: Moved (server-side) 2021/12/01 05:39:46 INFO : three.txt: Moved into backup dir 2021/12/01 05:39:51 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" 2021/12/01 05:39:51 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k" 2021/12/01 05:39:52 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "tr2hj63d80ftlmvm6a952snjcc" 2021/12/01 05:39:52 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" 2021/12/01 05:39:52 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "tr2hj63d80ftlmvm6a952snjcc" 2021/12/01 05:39:52 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" --- PASS: TestSyncBackupDir (29.78s) === RUN TestSyncBackupDirWithSuffix run.go:181: Remote "Encrypted drive 'TestCryptDrive:rclone-test-beyemut3qobodab0bifemeh5'", Local "Local file system at /tmp/rclone1663228036", Modify Window "1ms" 2021/12/01 05:39:55 DEBUG : dst/one: md5 = 05e4a6b785f2cd1ab7bdbda84f3682bb OK 2021/12/01 05:39:57 DEBUG : dst/two: md5 = 50195c7012b4ef378cbdf93c22cf0dab OK 2021/12/01 05:39:58 DEBUG : dst/three.txt: md5 = 11ecb959b1b32a513112a3a826527b73 OK 2021/12/01 05:39:59 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-beyemut3qobodab0bifemeh5/dst" 2021/12/01 05:39:59 DEBUG : Creating backend with remote "TestDrive:crypt/arh3eumf1lvqc7k624qhttajs1a59mn77ptb70pl7o7pgr4hoe7n4slnp15daij7ucl94ssdmkc00/31u3jie661vd5p8j7rtc3hgbh0" 2021/12/01 05:40:00 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-beyemut3qobodab0bifemeh5/backup" 2021/12/01 05:40:00 DEBUG : Creating backend with remote "TestDrive:crypt/arh3eumf1lvqc7k624qhttajs1a59mn77ptb70pl7o7pgr4hoe7n4slnp15daij7ucl94ssdmkc00/1nrff024r7pq65ecp72fc28jb0" 2021/12/01 05:40:02 DEBUG : one: Sizes differ (src 4 vs dst 3) 2021/12/01 05:40:02 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2021/12/01 05:40:02 DEBUG : two: Unchanged skipping 2021/12/01 05:40:02 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-beyemut3qobodab0bifemeh5/dst': Waiting for checks to finish 2021/12/01 05:40:04 INFO : one: Moved (server-side) to: one.bak 2021/12/01 05:40:04 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-beyemut3qobodab0bifemeh5/dst': Waiting for transfers to finish 2021/12/01 05:40:06 DEBUG : one: md5 = ecf5eae69a07c39f3b169405051bdd83 OK 2021/12/01 05:40:06 INFO : one: Copied (new) 2021/12/01 05:40:06 DEBUG : Waiting for deletions to finish 2021/12/01 05:40:07 INFO : three.txt: Moved (server-side) to: three.txt.bak 2021/12/01 05:40:07 INFO : three.txt: Moved into backup dir 2021/12/01 05:40:09 DEBUG : dst/three.txt: md5 = 4099043181ba0ec99189e46b0dffe7ec OK 2021/12/01 05:40:10 DEBUG : one: Sizes differ (src 5 vs dst 4) 2021/12/01 05:40:10 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2021/12/01 05:40:10 DEBUG : two: Unchanged skipping 2021/12/01 05:40:10 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-beyemut3qobodab0bifemeh5/dst': Waiting for checks to finish 2021/12/01 05:40:11 INFO : one.bak: Deleted 2021/12/01 05:40:12 INFO : one: Moved (server-side) to: one.bak 2021/12/01 05:40:12 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-beyemut3qobodab0bifemeh5/dst': Waiting for transfers to finish 2021/12/01 05:40:13 DEBUG : one: md5 = 5822ed89ab99ea5a6cf775bfed459101 OK 2021/12/01 05:40:13 INFO : one: Copied (new) 2021/12/01 05:40:13 DEBUG : Waiting for deletions to finish 2021/12/01 05:40:14 INFO : three.txt.bak: Deleted 2021/12/01 05:40:15 INFO : three.txt: Moved (server-side) to: three.txt.bak 2021/12/01 05:40:15 INFO : three.txt: Moved into backup dir 2021/12/01 05:40:19 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" 2021/12/01 05:40:19 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k" 2021/12/01 05:40:20 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "sk91qgsqfn0r271r2ehsaoc20c" 2021/12/01 05:40:20 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "qltcak2uaegtmcoa8vijdppbp8" 2021/12/01 05:40:20 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "qltcak2uaegtmcoa8vijdppbp8" 2021/12/01 05:40:20 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "sk91qgsqfn0r271r2ehsaoc20c" --- PASS: TestSyncBackupDirWithSuffix (28.34s) === RUN TestSyncBackupDirWithSuffixKeepExtension run.go:181: Remote "Encrypted drive 'TestCryptDrive:rclone-test-beyemut3qobodab0bifemeh5'", Local "Local file system at /tmp/rclone1663228036", Modify Window "1ms" 2021/12/01 05:40:24 DEBUG : dst/one: md5 = 33a031d8d37a0be2b11c14e81166fda0 OK 2021/12/01 05:40:25 DEBUG : dst/two: md5 = 47f869b983a50651791d9a863c04bd29 OK 2021/12/01 05:40:27 DEBUG : dst/three.txt: md5 = a1279a10bc4b58fe59927f1278d9b109 OK 2021/12/01 05:40:28 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-beyemut3qobodab0bifemeh5/dst" 2021/12/01 05:40:28 DEBUG : Creating backend with remote "TestDrive:crypt/arh3eumf1lvqc7k624qhttajs1a59mn77ptb70pl7o7pgr4hoe7n4slnp15daij7ucl94ssdmkc00/31u3jie661vd5p8j7rtc3hgbh0" 2021/12/01 05:40:29 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-beyemut3qobodab0bifemeh5/backup" 2021/12/01 05:40:29 DEBUG : Creating backend with remote "TestDrive:crypt/arh3eumf1lvqc7k624qhttajs1a59mn77ptb70pl7o7pgr4hoe7n4slnp15daij7ucl94ssdmkc00/1nrff024r7pq65ecp72fc28jb0" 2021/12/01 05:40:31 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-beyemut3qobodab0bifemeh5/dst': Waiting for checks to finish 2021/12/01 05:40:31 DEBUG : one: Sizes differ (src 4 vs dst 3) 2021/12/01 05:40:31 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2021/12/01 05:40:31 DEBUG : two: Unchanged skipping 2021/12/01 05:40:33 INFO : one: Moved (server-side) to: one-2019-01-01 2021/12/01 05:40:33 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-beyemut3qobodab0bifemeh5/dst': Waiting for transfers to finish 2021/12/01 05:40:35 DEBUG : one: md5 = 47117583150df923759ade185040c669 OK 2021/12/01 05:40:35 INFO : one: Copied (new) 2021/12/01 05:40:35 DEBUG : Waiting for deletions to finish 2021/12/01 05:40:36 INFO : three.txt: Moved (server-side) to: three-2019-01-01.txt 2021/12/01 05:40:36 INFO : three.txt: Moved into backup dir 2021/12/01 05:40:38 DEBUG : dst/three.txt: md5 = 7aa71e8f4479a8b94ffcf73baea2e0f9 OK 2021/12/01 05:40:39 DEBUG : one: Sizes differ (src 5 vs dst 4) 2021/12/01 05:40:39 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2021/12/01 05:40:39 DEBUG : two: Unchanged skipping 2021/12/01 05:40:39 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-beyemut3qobodab0bifemeh5/dst': Waiting for checks to finish 2021/12/01 05:40:40 INFO : one-2019-01-01: Deleted 2021/12/01 05:40:41 INFO : one: Moved (server-side) to: one-2019-01-01 2021/12/01 05:40:41 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-beyemut3qobodab0bifemeh5/dst': Waiting for transfers to finish 2021/12/01 05:40:43 DEBUG : one: md5 = bd351e38453d34cf302e2bdd603b7ad9 OK 2021/12/01 05:40:43 INFO : one: Copied (new) 2021/12/01 05:40:43 DEBUG : Waiting for deletions to finish 2021/12/01 05:40:44 INFO : three-2019-01-01.txt: Deleted 2021/12/01 05:40:45 INFO : three.txt: Moved (server-side) to: three-2019-01-01.txt 2021/12/01 05:40:45 INFO : three.txt: Moved into backup dir 2021/12/01 05:40:49 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" 2021/12/01 05:40:49 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k" 2021/12/01 05:40:50 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "qtq2f6qq4lgpsmj88vb7147qje3prudmtfdtr2342fth58vo9a50" 2021/12/01 05:40:50 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "jcjl1bv3ep0v8kt35lqql1co90" 2021/12/01 05:40:50 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "jcjl1bv3ep0v8kt35lqql1co90" 2021/12/01 05:40:50 DEBUG : 1nrff024r7pq65ecp72fc28jb0: Rmdir: contains trashed file: "qtq2f6qq4lgpsmj88vb7147qje3prudmtfdtr2342fth58vo9a50" --- PASS: TestSyncBackupDirWithSuffixKeepExtension (29.76s) === RUN TestSyncBackupDirSuffixOnly run.go:181: Remote "Encrypted drive 'TestCryptDrive:rclone-test-beyemut3qobodab0bifemeh5'", Local "Local file system at /tmp/rclone1663228036", Modify Window "1ms" 2021/12/01 05:40:54 DEBUG : dst/one: md5 = d67fa9f08ba8ef21698c87752a9050e9 OK 2021/12/01 05:40:55 DEBUG : dst/two: md5 = 05dd81a1903d0c74e36388cae95c40a2 OK 2021/12/01 05:40:57 DEBUG : dst/three.txt: md5 = 4b389222ad987011e4c8ac47e7410864 OK 2021/12/01 05:40:57 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-beyemut3qobodab0bifemeh5/dst" 2021/12/01 05:40:57 DEBUG : Creating backend with remote "TestDrive:crypt/arh3eumf1lvqc7k624qhttajs1a59mn77ptb70pl7o7pgr4hoe7n4slnp15daij7ucl94ssdmkc00/31u3jie661vd5p8j7rtc3hgbh0" 2021/12/01 05:40:59 DEBUG : one: Sizes differ (src 4 vs dst 3) 2021/12/01 05:40:59 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2021/12/01 05:40:59 DEBUG : two: Unchanged skipping 2021/12/01 05:40:59 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-beyemut3qobodab0bifemeh5/dst': Waiting for checks to finish 2021/12/01 05:41:00 INFO : one: Moved (server-side) to: one.bak 2021/12/01 05:41:00 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-beyemut3qobodab0bifemeh5/dst': Waiting for transfers to finish 2021/12/01 05:41:01 DEBUG : one: md5 = dbf001ae55611e3d7ab5990462a4012e OK 2021/12/01 05:41:01 INFO : one: Copied (new) 2021/12/01 05:41:01 DEBUG : Waiting for deletions to finish 2021/12/01 05:41:02 INFO : three.txt: Moved (server-side) to: three.txt.bak 2021/12/01 05:41:02 INFO : three.txt: Moved into backup dir 2021/12/01 05:41:05 DEBUG : dst/three.txt: md5 = e7d31f8b33adcc4d55f578b2fd3eda1b OK 2021/12/01 05:41:06 DEBUG : three.txt.bak: Excluded 2021/12/01 05:41:06 DEBUG : one.bak: Excluded 2021/12/01 05:41:06 DEBUG : one: Sizes differ (src 5 vs dst 4) 2021/12/01 05:41:06 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2021/12/01 05:41:06 DEBUG : two: Unchanged skipping 2021/12/01 05:41:06 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-beyemut3qobodab0bifemeh5/dst': Waiting for checks to finish 2021/12/01 05:41:06 INFO : one.bak: Deleted 2021/12/01 05:41:07 INFO : one: Moved (server-side) to: one.bak 2021/12/01 05:41:07 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-beyemut3qobodab0bifemeh5/dst': Waiting for transfers to finish 2021/12/01 05:41:09 DEBUG : one: md5 = 9ac1d2abda06845ca970820819fc9194 OK 2021/12/01 05:41:09 INFO : one: Copied (new) 2021/12/01 05:41:09 DEBUG : Waiting for deletions to finish 2021/12/01 05:41:10 INFO : three.txt.bak: Deleted 2021/12/01 05:41:10 INFO : three.txt: Moved (server-side) to: three.txt.bak 2021/12/01 05:41:10 INFO : three.txt: Moved into backup dir 2021/12/01 05:41:15 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" 2021/12/01 05:41:15 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "sk91qgsqfn0r271r2ehsaoc20c" 2021/12/01 05:41:15 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "qltcak2uaegtmcoa8vijdppbp8" 2021/12/01 05:41:15 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "sk91qgsqfn0r271r2ehsaoc20c" 2021/12/01 05:41:15 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "qltcak2uaegtmcoa8vijdppbp8" 2021/12/01 05:41:15 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k" --- PASS: TestSyncBackupDirSuffixOnly (24.75s) === RUN TestSyncSuffix run.go:181: Remote "Encrypted drive 'TestCryptDrive:rclone-test-beyemut3qobodab0bifemeh5'", Local "Local file system at /tmp/rclone1663228036", Modify Window "1ms" 2021/12/01 05:41:18 DEBUG : dst/one: md5 = adddde2b5ff667d6defac4ab5142e09e OK 2021/12/01 05:41:20 DEBUG : dst/two: md5 = d8e445129e07a10e18822c1ca3fa3a7b OK 2021/12/01 05:41:21 DEBUG : dst/three.txt: md5 = 81d5a8a3386a13b1f32a71e49732f18f OK 2021/12/01 05:41:22 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-beyemut3qobodab0bifemeh5/dst" 2021/12/01 05:41:22 DEBUG : Creating backend with remote "TestDrive:crypt/arh3eumf1lvqc7k624qhttajs1a59mn77ptb70pl7o7pgr4hoe7n4slnp15daij7ucl94ssdmkc00/31u3jie661vd5p8j7rtc3hgbh0" 2021/12/01 05:41:23 DEBUG : one: Sizes differ (src 4 vs dst 3) 2021/12/01 05:41:24 INFO : one: Moved (server-side) to: one.bak 2021/12/01 05:41:25 DEBUG : one: md5 = 0a32757fb1d6997d706a4243e63e6b1e OK 2021/12/01 05:41:25 INFO : one: Copied (new) 2021/12/01 05:41:26 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2021/12/01 05:41:26 DEBUG : two: Unchanged skipping 2021/12/01 05:41:26 DEBUG : three.txt: Sizes differ (src 6 vs dst 5) 2021/12/01 05:41:27 INFO : three.txt: Moved (server-side) to: three.txt.bak 2021/12/01 05:41:28 DEBUG : three.txt: md5 = 8cc0e36be2a494797a8297b29f2c1c52 OK 2021/12/01 05:41:28 INFO : three.txt: Copied (new) 2021/12/01 05:41:30 DEBUG : one: Sizes differ (src 5 vs dst 4) 2021/12/01 05:41:31 INFO : one.bak: Deleted 2021/12/01 05:41:31 INFO : one: Moved (server-side) to: one.bak 2021/12/01 05:41:33 DEBUG : one: md5 = 63b8c7f598085ae2a379ff75c9fc4efa OK 2021/12/01 05:41:33 INFO : one: Copied (new) 2021/12/01 05:41:33 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2021/12/01 05:41:33 DEBUG : two: Unchanged skipping 2021/12/01 05:41:33 DEBUG : three.txt: Sizes differ (src 19 vs dst 6) 2021/12/01 05:41:34 INFO : three.txt.bak: Deleted 2021/12/01 05:41:35 INFO : three.txt: Moved (server-side) to: three.txt.bak 2021/12/01 05:41:37 DEBUG : three.txt: md5 = 61ceef2b37c348c68b300e2b955db50c OK 2021/12/01 05:41:37 INFO : three.txt: Copied (new) 2021/12/01 05:41:42 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "tr2hj63d80ftlmvm6a952snjcc" 2021/12/01 05:41:42 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" 2021/12/01 05:41:42 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "qltcak2uaegtmcoa8vijdppbp8" 2021/12/01 05:41:42 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "sk91qgsqfn0r271r2ehsaoc20c" 2021/12/01 05:41:42 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "sk91qgsqfn0r271r2ehsaoc20c" 2021/12/01 05:41:42 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "qltcak2uaegtmcoa8vijdppbp8" 2021/12/01 05:41:42 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k" --- PASS: TestSyncSuffix (27.03s) === RUN TestSyncSuffixKeepExtension run.go:181: Remote "Encrypted drive 'TestCryptDrive:rclone-test-beyemut3qobodab0bifemeh5'", Local "Local file system at /tmp/rclone1663228036", Modify Window "1ms" 2021/12/01 05:41:45 DEBUG : dst/one: md5 = ed0ccde1c5846e7be0d60d3236c9f62b OK 2021/12/01 05:41:47 DEBUG : dst/two: md5 = 4762fc9754facb4d302d11eba4de24bf OK 2021/12/01 05:41:49 DEBUG : dst/three.txt: md5 = 9d6e23b2928395d33237dbd36020d52f OK 2021/12/01 05:41:49 DEBUG : Creating backend with remote "TestCryptDrive:rclone-test-beyemut3qobodab0bifemeh5/dst" 2021/12/01 05:41:49 DEBUG : Creating backend with remote "TestDrive:crypt/arh3eumf1lvqc7k624qhttajs1a59mn77ptb70pl7o7pgr4hoe7n4slnp15daij7ucl94ssdmkc00/31u3jie661vd5p8j7rtc3hgbh0" 2021/12/01 05:41:51 DEBUG : one: Sizes differ (src 4 vs dst 3) 2021/12/01 05:41:52 INFO : one: Moved (server-side) to: one-2019-01-01 2021/12/01 05:41:53 DEBUG : one: md5 = c0608e42c286f213d36243a04c282e2c OK 2021/12/01 05:41:53 INFO : one: Copied (new) 2021/12/01 05:41:54 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2021/12/01 05:41:54 DEBUG : two: Unchanged skipping 2021/12/01 05:41:54 DEBUG : three.txt: Sizes differ (src 6 vs dst 5) 2021/12/01 05:41:55 INFO : three.txt: Moved (server-side) to: three-2019-01-01.txt 2021/12/01 05:41:57 DEBUG : three.txt: md5 = 8f4da31380c0f3ab9ac0fa7559ecee9e OK 2021/12/01 05:41:57 INFO : three.txt: Copied (new) 2021/12/01 05:41:58 DEBUG : one: Sizes differ (src 5 vs dst 4) 2021/12/01 05:41:59 INFO : one-2019-01-01: Deleted 2021/12/01 05:42:00 INFO : one: Moved (server-side) to: one-2019-01-01 2021/12/01 05:42:01 DEBUG : one: md5 = 02fb8bd0190d761b04339b375ae31e6b OK 2021/12/01 05:42:01 INFO : one: Copied (new) 2021/12/01 05:42:02 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2021/12/01 05:42:02 DEBUG : two: Unchanged skipping 2021/12/01 05:42:02 DEBUG : three.txt: Sizes differ (src 19 vs dst 6) 2021/12/01 05:42:03 INFO : three-2019-01-01.txt: Deleted 2021/12/01 05:42:04 INFO : three.txt: Moved (server-side) to: three-2019-01-01.txt 2021/12/01 05:42:05 DEBUG : three.txt: md5 = ddfca0a331cb17e35847e49debb171b7 OK 2021/12/01 05:42:05 INFO : three.txt: Copied (new) 2021/12/01 05:42:10 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "tr2hj63d80ftlmvm6a952snjcc" 2021/12/01 05:42:10 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "0828u6q2p8d62qeklrkkuf10uc" 2021/12/01 05:42:10 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "jcjl1bv3ep0v8kt35lqql1co90" 2021/12/01 05:42:10 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "qtq2f6qq4lgpsmj88vb7147qje3prudmtfdtr2342fth58vo9a50" 2021/12/01 05:42:10 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "jcjl1bv3ep0v8kt35lqql1co90" 2021/12/01 05:42:10 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "qtq2f6qq4lgpsmj88vb7147qje3prudmtfdtr2342fth58vo9a50" 2021/12/01 05:42:10 DEBUG : 31u3jie661vd5p8j7rtc3hgbh0: Rmdir: contains trashed file: "keafetfvtbmgo6tsdvcbj32i0k" --- PASS: TestSyncSuffixKeepExtension (28.41s) === RUN TestSyncUTFNorm run.go:181: Remote "Encrypted drive 'TestCryptDrive:rclone-test-beyemut3qobodab0bifemeh5'", Local "Local file system at /tmp/rclone1663228036", Modify Window "1ms" 2021/12/01 05:42:13 DEBUG : Testêé: md5 = a7d7b9f50e234fdba0daa03f1624b904 OK 2021/12/01 05:42:13 DEBUG : Testêé: Sizes differ (src 14 vs dst 18) 2021/12/01 05:42:13 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-beyemut3qobodab0bifemeh5': Waiting for checks to finish 2021/12/01 05:42:13 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-beyemut3qobodab0bifemeh5': Waiting for transfers to finish 2021/12/01 05:42:15 DEBUG : Testêé: md5 = d0ada0e942df19a50dd097661adbb7bd OK 2021/12/01 05:42:15 INFO : Testêé: Copied (replaced existing) 2021/12/01 05:42:15 DEBUG : Waiting for deletions to finish --- PASS: TestSyncUTFNorm (5.04s) === RUN TestSyncImmutable run.go:181: Remote "Encrypted drive 'TestCryptDrive:rclone-test-beyemut3qobodab0bifemeh5'", Local "Local file system at /tmp/rclone1663228036", Modify Window "1ms" 2021/12/01 05:42:17 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-beyemut3qobodab0bifemeh5': Waiting for checks to finish 2021/12/01 05:42:17 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-beyemut3qobodab0bifemeh5': Waiting for transfers to finish 2021/12/01 05:42:18 DEBUG : existing: md5 = fc975a25ae898383b6000a19ab2d98bb OK 2021/12/01 05:42:18 INFO : existing: Copied (new) 2021/12/01 05:42:18 DEBUG : Waiting for deletions to finish 2021/12/01 05:42:19 DEBUG : existing: Sizes differ (src 8 vs dst 6) 2021/12/01 05:42:19 ERROR : existing: Source and destination exist but do not match: immutable file modified 2021/12/01 05:42:19 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-beyemut3qobodab0bifemeh5': Waiting for checks to finish 2021/12/01 05:42:19 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-beyemut3qobodab0bifemeh5': Waiting for transfers to finish 2021/12/01 05:42:19 ERROR : Encrypted drive 'TestCryptDrive:rclone-test-beyemut3qobodab0bifemeh5': not deleting files as there were IO errors 2021/12/01 05:42:19 ERROR : Encrypted drive 'TestCryptDrive:rclone-test-beyemut3qobodab0bifemeh5': not deleting directories as there were IO errors --- PASS: TestSyncImmutable (4.69s) === RUN TestSyncIgnoreCase run.go:181: Remote "Encrypted drive 'TestCryptDrive:rclone-test-beyemut3qobodab0bifemeh5'", Local "Local file system at /tmp/rclone1663228036", Modify Window "1ms" 2021/12/01 05:42:22 DEBUG : EXISTING: md5 = 4cb11927e80bdf09614ed2c85b88a749 OK 2021/12/01 05:42:23 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-beyemut3qobodab0bifemeh5': Waiting for checks to finish 2021/12/01 05:42:23 DEBUG : existing: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2021/12/01 05:42:23 DEBUG : existing: Unchanged skipping 2021/12/01 05:42:23 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-beyemut3qobodab0bifemeh5': Waiting for transfers to finish 2021/12/01 05:42:23 DEBUG : Waiting for deletions to finish 2021/12/01 05:42:23 INFO : There was nothing to transfer --- PASS: TestSyncIgnoreCase (3.75s) === RUN TestMaxTransfer === RUN TestMaxTransfer/Hard run.go:181: Remote "Encrypted drive 'TestCryptDrive:rclone-test-beyemut3qobodab0bifemeh5'", Local "Local file system at /tmp/rclone1663228036", Modify Window "1ms" sync_test.go:1989: This test only runs on local === RUN TestMaxTransfer/Soft run.go:181: Remote "Encrypted drive 'TestCryptDrive:rclone-test-beyemut3qobodab0bifemeh5'", Local "Local file system at /tmp/rclone1663228036", Modify Window "1ms" sync_test.go:1989: This test only runs on local === RUN TestMaxTransfer/Cautious run.go:181: Remote "Encrypted drive 'TestCryptDrive:rclone-test-beyemut3qobodab0bifemeh5'", Local "Local file system at /tmp/rclone1663228036", Modify Window "1ms" sync_test.go:1989: This test only runs on local --- PASS: TestMaxTransfer (1.60s) --- SKIP: TestMaxTransfer/Hard (0.53s) --- SKIP: TestMaxTransfer/Soft (0.55s) --- SKIP: TestMaxTransfer/Cautious (0.52s) === RUN TestSyncConcurrentDelete run.go:181: Remote "Encrypted drive 'TestCryptDrive:rclone-test-beyemut3qobodab0bifemeh5'", Local "Local file system at /tmp/rclone1663228036", Modify Window "1ms" 2021/12/01 05:42:28 DEBUG : both0: md5 = 81bef07ed5c64bd64082e6c967c792a3 OK 2021/12/01 05:42:29 DEBUG : only0: md5 = 220333c478e52eac54b7aa03b0759e68 OK 2021/12/01 05:42:31 DEBUG : both1: md5 = 5481c62805cb20743db3d574155f4654 OK 2021/12/01 05:42:33 DEBUG : only1: md5 = 7e1a1c7404734f3265d7b8f2c74e5933 OK 2021/12/01 05:42:34 DEBUG : both2: md5 = f90bc0287b20005ba3e8de7811f82f35 OK 2021/12/01 05:42:36 DEBUG : only2: md5 = b7333995924a7180f6375a31e5452fa6 OK 2021/12/01 05:42:37 DEBUG : both3: md5 = 4d1b6f4893e1f9439423eb06c23631c1 OK 2021/12/01 05:42:39 DEBUG : only3: md5 = a9f8aeb1909b4999bd0ee0cc9ce53321 OK 2021/12/01 05:42:40 DEBUG : both4: md5 = 2fcb95fe5281b2fd99c87f976912296d OK 2021/12/01 05:42:42 DEBUG : only4: md5 = 7bdfd05ca443f195418acdb5c16ea4a1 OK 2021/12/01 05:42:43 DEBUG : both5: md5 = fef71d2fa8ba1d33f6213abd0de9a34f OK 2021/12/01 05:42:45 DEBUG : only5: md5 = a7ed0acc96a32bac44dd312fad5cb78b OK 2021/12/01 05:42:47 DEBUG : both6: md5 = c9001f831a593eac1e537920bc32a87c OK 2021/12/01 05:42:48 DEBUG : only6: md5 = 6cb1e6c79aabe609727f1a1276f8f79d OK 2021/12/01 05:42:50 DEBUG : both7: md5 = 69f256c3cca9471cf0478998ee0ee6d1 OK 2021/12/01 05:42:51 DEBUG : only7: md5 = d60397ac87c00f553669161ccab6d160 OK 2021/12/01 05:42:53 DEBUG : both8: md5 = b6e8183b849cf741d587f756b912ded9 OK 2021/12/01 05:42:54 DEBUG : only8: md5 = f6b6f398967481456d4ad2709159162a OK 2021/12/01 05:42:56 DEBUG : both9: md5 = 2a439aef6a67eb2c6fa62569ed880fdd OK 2021/12/01 05:42:57 DEBUG : only9: md5 = 57aa2e39f5f9c3e25ab0432c80024d3d OK 2021/12/01 05:42:59 DEBUG : both10: md5 = 8386269cfe94208ccf6ad769b3d41dd0 OK 2021/12/01 05:43:01 DEBUG : only10: md5 = afa526d3631f6cc1b20c05046fb50c4f OK 2021/12/01 05:43:02 DEBUG : both11: md5 = 5cac39a729c35fefd061de34473cf6ac OK 2021/12/01 05:43:04 DEBUG : only11: md5 = bb2cdd4013f2a11640706a10e9b7f69c OK 2021/12/01 05:43:05 DEBUG : both12: md5 = 9ad5ed53a32fe0e38f5b2160cfa9d225 OK 2021/12/01 05:43:07 DEBUG : only12: md5 = 0c177b74a621e19f3e78006c12203c57 OK 2021/12/01 05:43:08 DEBUG : both13: md5 = 3b246ffe608d92e45d6d5aaa3eef2e17 OK 2021/12/01 05:43:10 DEBUG : only13: md5 = 934aa6c9a8a849c2f9271a7acf6c4b4a OK 2021/12/01 05:43:14 DEBUG : both14: md5 = 030b3084bf31673e5c01763de2627c5a OK 2021/12/01 05:43:16 DEBUG : only14: md5 = d44d9cc4778f9af4d18de16275d17c22 OK 2021/12/01 05:43:18 DEBUG : both15: md5 = b1faea8c9692046c2d52891e232fdc48 OK 2021/12/01 05:43:19 DEBUG : only15: md5 = be09028063bbe781b23c9163ddd79a36 OK 2021/12/01 05:43:21 DEBUG : both16: md5 = 6bfe6dea52adec2d7332855e178893d0 OK 2021/12/01 05:43:22 DEBUG : only16: md5 = 597d2617a6a69d5dfa529177182398f8 OK 2021/12/01 05:43:24 DEBUG : both17: md5 = f62dbdb4fbbbce65933e14f41f65b53e OK 2021/12/01 05:43:25 DEBUG : only17: md5 = 1fe7ed440b2e963f906121298c7ee2e0 OK 2021/12/01 05:43:27 DEBUG : both18: md5 = 0596a548753dea2bcd32803dcf2964bf OK 2021/12/01 05:43:28 DEBUG : only18: md5 = d592a8de0f687adf17e2085e66ed8942 OK 2021/12/01 05:43:30 DEBUG : both19: md5 = defe93d6002cdf5a9f5830f144f0be9f OK 2021/12/01 05:43:32 DEBUG : only19: md5 = 7fe96e5a316efc0a1aa501e5b59d94b6 OK 2021/12/01 05:43:33 DEBUG : both0: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2021/12/01 05:43:33 DEBUG : both0: Unchanged skipping 2021/12/01 05:43:33 DEBUG : both10: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2021/12/01 05:43:33 DEBUG : both10: Unchanged skipping 2021/12/01 05:43:33 DEBUG : both11: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2021/12/01 05:43:33 DEBUG : both1: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2021/12/01 05:43:33 DEBUG : both1: Unchanged skipping 2021/12/01 05:43:33 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-beyemut3qobodab0bifemeh5': Waiting for checks to finish 2021/12/01 05:43:33 DEBUG : both12: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2021/12/01 05:43:33 DEBUG : both12: Unchanged skipping 2021/12/01 05:43:33 DEBUG : both14: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2021/12/01 05:43:33 DEBUG : both14: Unchanged skipping 2021/12/01 05:43:33 DEBUG : both15: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2021/12/01 05:43:33 DEBUG : both13: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2021/12/01 05:43:33 DEBUG : both13: Unchanged skipping 2021/12/01 05:43:33 DEBUG : both17: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2021/12/01 05:43:33 DEBUG : both17: Unchanged skipping 2021/12/01 05:43:33 DEBUG : both16: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2021/12/01 05:43:33 DEBUG : both16: Unchanged skipping 2021/12/01 05:43:33 DEBUG : both15: Unchanged skipping 2021/12/01 05:43:33 DEBUG : both19: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2021/12/01 05:43:33 DEBUG : both19: Unchanged skipping 2021/12/01 05:43:33 DEBUG : both3: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2021/12/01 05:43:33 DEBUG : both3: Unchanged skipping 2021/12/01 05:43:33 DEBUG : both2: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2021/12/01 05:43:33 DEBUG : both2: Unchanged skipping 2021/12/01 05:43:33 DEBUG : both11: Unchanged skipping 2021/12/01 05:43:33 DEBUG : both5: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2021/12/01 05:43:33 DEBUG : both6: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2021/12/01 05:43:33 DEBUG : both5: Unchanged skipping 2021/12/01 05:43:33 DEBUG : both6: Unchanged skipping 2021/12/01 05:43:33 DEBUG : both7: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2021/12/01 05:43:33 DEBUG : both7: Unchanged skipping 2021/12/01 05:43:33 DEBUG : both9: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2021/12/01 05:43:33 DEBUG : both9: Unchanged skipping 2021/12/01 05:43:33 DEBUG : both8: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2021/12/01 05:43:33 DEBUG : both18: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2021/12/01 05:43:33 DEBUG : both18: Unchanged skipping 2021/12/01 05:43:33 DEBUG : both4: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2021/12/01 05:43:33 DEBUG : both4: Unchanged skipping 2021/12/01 05:43:33 DEBUG : both8: Unchanged skipping 2021/12/01 05:43:33 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-beyemut3qobodab0bifemeh5': Waiting for transfers to finish 2021/12/01 05:43:33 DEBUG : Waiting for deletions to finish 2021/12/01 05:43:33 INFO : only10: Deleted 2021/12/01 05:43:33 INFO : only9: Deleted 2021/12/01 05:43:33 INFO : only15: Deleted 2021/12/01 05:43:33 INFO : only5: Deleted 2021/12/01 05:43:34 INFO : only11: Deleted 2021/12/01 05:43:34 INFO : only14: Deleted 2021/12/01 05:43:34 INFO : only13: Deleted 2021/12/01 05:43:34 INFO : only17: Deleted 2021/12/01 05:43:35 INFO : only4: Deleted 2021/12/01 05:43:35 INFO : only18: Deleted 2021/12/01 05:43:35 INFO : only3: Deleted 2021/12/01 05:43:35 INFO : only7: Deleted 2021/12/01 05:43:35 INFO : only8: Deleted 2021/12/01 05:43:35 INFO : only0: Deleted 2021/12/01 05:43:36 INFO : only12: Deleted 2021/12/01 05:43:36 INFO : only1: Deleted 2021/12/01 05:43:36 INFO : only6: Deleted 2021/12/01 05:43:36 INFO : only16: Deleted 2021/12/01 05:43:36 INFO : only19: Deleted 2021/12/01 05:43:36 INFO : only2: Deleted 2021/12/01 05:43:36 INFO : There was nothing to transfer --- PASS: TestSyncConcurrentDelete (84.09s) === RUN TestSyncConcurrentTruncate run.go:181: Remote "Encrypted drive 'TestCryptDrive:rclone-test-beyemut3qobodab0bifemeh5'", Local "Local file system at /tmp/rclone1663228036", Modify Window "1ms" 2021/12/01 05:43:52 DEBUG : both0: md5 = 8521f663874d23884951c3a7a62dd5d3 OK 2021/12/01 05:43:53 DEBUG : only0: md5 = de14b180a6f0788931bdece12b9d0c33 OK 2021/12/01 05:43:55 DEBUG : both1: md5 = e9e06a741dca8289e01ab5c44453a8c0 OK 2021/12/01 05:43:56 DEBUG : only1: md5 = cb70da1582a76349ccb793e873f6a1de OK 2021/12/01 05:43:58 DEBUG : both2: md5 = 813adda4a0885918bd3abdde1f40fcff OK 2021/12/01 05:44:00 DEBUG : only2: md5 = aff55fe5032da54129fef006c0b427d2 OK 2021/12/01 05:44:01 DEBUG : both3: md5 = bc5dc662304586a6e898750deea78fb5 OK 2021/12/01 05:44:03 DEBUG : only3: md5 = f3ef7324a2d64e0b796c5d26628000d8 OK 2021/12/01 05:44:04 DEBUG : both4: md5 = 373fd861d6cc44e2395e42837e457694 OK 2021/12/01 05:44:06 DEBUG : only4: md5 = 6450c977e217437b6525d98ddfb80dbf OK 2021/12/01 05:44:07 DEBUG : both5: md5 = f689643bdea2ea01dfc678b7492540d4 OK 2021/12/01 05:44:09 DEBUG : only5: md5 = 6f5e11289748e6d3dc8f796894a78d65 OK 2021/12/01 05:44:11 DEBUG : both6: md5 = 53ae55f80b92aa808fe8314107585cfd OK 2021/12/01 05:44:12 DEBUG : only6: md5 = 28d16f9f2f3e63edd0b9cd2deebe219b OK 2021/12/01 05:44:16 DEBUG : both7: md5 = f3943ce9984257861ab5868eecde9d00 OK 2021/12/01 05:44:17 DEBUG : only7: md5 = c5c6ac80056d30dd6ddcc8054cf5a229 OK 2021/12/01 05:44:19 DEBUG : both8: md5 = 67d65e5e7f78a183c5ab468ab011a1dc OK 2021/12/01 05:44:21 DEBUG : only8: md5 = 8492a2dd0bec94a800fcbbe7a0eaec61 OK 2021/12/01 05:44:22 DEBUG : both9: md5 = 17458bd99ca8587a3215ea6b06e6a132 OK 2021/12/01 05:44:24 DEBUG : only9: md5 = 8d07486228de4a4da53687df02123b81 OK 2021/12/01 05:44:25 DEBUG : both10: md5 = 39c99af190ee54132ff3db7468acb745 OK 2021/12/01 05:44:27 DEBUG : only10: md5 = deac712b9a37a6bd8d8c9f2016b922ee OK 2021/12/01 05:44:28 DEBUG : both11: md5 = baf4eb5e87c9591903d5f9395f799d52 OK 2021/12/01 05:44:30 DEBUG : only11: md5 = 130f3ba3f059ef50e5e89ed18031a283 OK 2021/12/01 05:44:32 DEBUG : both12: md5 = ae5a224b46746e8378ec1c59742a49f1 OK 2021/12/01 05:44:33 DEBUG : only12: md5 = 7a88c0d793e590abec1d109e23a0c2f3 OK 2021/12/01 05:44:35 DEBUG : both13: md5 = 83fdd8c19b4b8c31547d0e470b920648 OK 2021/12/01 05:44:36 DEBUG : only13: md5 = ddc5ced3f419160f5de3f3dcd106a7fb OK 2021/12/01 05:44:38 DEBUG : both14: md5 = 5d6f2ef5b0b9991c7be0b565b3f7c49a OK 2021/12/01 05:44:40 DEBUG : only14: md5 = a9080a4b1cc93b1440cafece74a1e510 OK 2021/12/01 05:44:41 DEBUG : both15: md5 = 458ab4c3aeeea9e2f46500d9ff944bf6 OK 2021/12/01 05:44:43 DEBUG : only15: md5 = c27bfd4114a9dc3e2bbaa867e829952b OK 2021/12/01 05:44:45 DEBUG : both16: md5 = 1c654716e631813f4f2c5d2fefb5a0cc OK 2021/12/01 05:44:46 DEBUG : only16: md5 = af14c671e83937e2198c5006db3325aa OK 2021/12/01 05:44:48 DEBUG : both17: md5 = 4866d6ba9714792f820e4b5b7e5f2a6a OK 2021/12/01 05:44:49 DEBUG : only17: md5 = 6615a8efee010bcc86b1e6436933cb77 OK 2021/12/01 05:44:51 DEBUG : both18: md5 = e186c4f00bf2ff06bbaa9508e8349a0d OK 2021/12/01 05:44:52 DEBUG : only18: md5 = 61c662b499f7f39ab2cb5004dd8e8706 OK 2021/12/01 05:44:54 DEBUG : both19: md5 = 639dec6a0ecebc53faf5285d5e44dd63 OK 2021/12/01 05:44:55 DEBUG : only19: md5 = c826d427ac0d12ce4e83b03ef6843512 OK 2021/12/01 05:44:56 DEBUG : both0: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2021/12/01 05:44:56 DEBUG : both0: Unchanged skipping 2021/12/01 05:44:56 DEBUG : both1: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2021/12/01 05:44:56 DEBUG : both1: Unchanged skipping 2021/12/01 05:44:56 DEBUG : both10: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2021/12/01 05:44:56 DEBUG : both10: Unchanged skipping 2021/12/01 05:44:56 DEBUG : both14: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2021/12/01 05:44:56 DEBUG : both14: Unchanged skipping 2021/12/01 05:44:56 DEBUG : both15: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2021/12/01 05:44:56 DEBUG : both15: Unchanged skipping 2021/12/01 05:44:56 DEBUG : both16: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2021/12/01 05:44:56 DEBUG : both16: Unchanged skipping 2021/12/01 05:44:56 DEBUG : both12: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2021/12/01 05:44:56 DEBUG : both12: Unchanged skipping 2021/12/01 05:44:56 DEBUG : both18: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2021/12/01 05:44:56 DEBUG : both18: Unchanged skipping 2021/12/01 05:44:56 DEBUG : both19: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2021/12/01 05:44:56 DEBUG : both19: Unchanged skipping 2021/12/01 05:44:56 DEBUG : both2: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2021/12/01 05:44:56 DEBUG : both2: Unchanged skipping 2021/12/01 05:44:56 DEBUG : both3: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2021/12/01 05:44:56 DEBUG : both3: Unchanged skipping 2021/12/01 05:44:56 DEBUG : both4: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2021/12/01 05:44:56 DEBUG : both4: Unchanged skipping 2021/12/01 05:44:56 DEBUG : both5: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2021/12/01 05:44:56 DEBUG : both5: Unchanged skipping 2021/12/01 05:44:56 DEBUG : both6: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2021/12/01 05:44:56 DEBUG : both6: Unchanged skipping 2021/12/01 05:44:56 DEBUG : both7: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2021/12/01 05:44:56 DEBUG : both7: Unchanged skipping 2021/12/01 05:44:56 DEBUG : both8: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2021/12/01 05:44:56 DEBUG : both8: Unchanged skipping 2021/12/01 05:44:56 DEBUG : both9: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2021/12/01 05:44:56 DEBUG : both9: Unchanged skipping 2021/12/01 05:44:56 DEBUG : only0: Sizes differ (src 0 vs dst 6) 2021/12/01 05:44:56 DEBUG : only1: Sizes differ (src 0 vs dst 6) 2021/12/01 05:44:56 DEBUG : only10: Sizes differ (src 0 vs dst 6) 2021/12/01 05:44:56 DEBUG : only11: Sizes differ (src 0 vs dst 6) 2021/12/01 05:44:56 DEBUG : only12: Sizes differ (src 0 vs dst 6) 2021/12/01 05:44:56 DEBUG : only13: Sizes differ (src 0 vs dst 6) 2021/12/01 05:44:56 DEBUG : only14: Sizes differ (src 0 vs dst 6) 2021/12/01 05:44:56 DEBUG : only15: Sizes differ (src 0 vs dst 6) 2021/12/01 05:44:56 DEBUG : only16: Sizes differ (src 0 vs dst 6) 2021/12/01 05:44:56 DEBUG : only17: Sizes differ (src 0 vs dst 6) 2021/12/01 05:44:56 DEBUG : only18: Sizes differ (src 0 vs dst 6) 2021/12/01 05:44:56 DEBUG : only19: Sizes differ (src 0 vs dst 6) 2021/12/01 05:44:56 DEBUG : only2: Sizes differ (src 0 vs dst 6) 2021/12/01 05:44:56 DEBUG : only3: Sizes differ (src 0 vs dst 6) 2021/12/01 05:44:56 DEBUG : only4: Sizes differ (src 0 vs dst 6) 2021/12/01 05:44:56 DEBUG : only5: Sizes differ (src 0 vs dst 6) 2021/12/01 05:44:56 DEBUG : only6: Sizes differ (src 0 vs dst 6) 2021/12/01 05:44:56 DEBUG : only7: Sizes differ (src 0 vs dst 6) 2021/12/01 05:44:56 DEBUG : only8: Sizes differ (src 0 vs dst 6) 2021/12/01 05:44:56 DEBUG : only9: Sizes differ (src 0 vs dst 6) 2021/12/01 05:44:56 DEBUG : both11: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2021/12/01 05:44:56 DEBUG : both11: Unchanged skipping 2021/12/01 05:44:56 DEBUG : both13: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2021/12/01 05:44:56 DEBUG : both13: Unchanged skipping 2021/12/01 05:44:56 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-beyemut3qobodab0bifemeh5': Waiting for checks to finish 2021/12/01 05:44:56 DEBUG : both17: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2021/12/01 05:44:56 DEBUG : both17: Unchanged skipping 2021/12/01 05:44:56 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-beyemut3qobodab0bifemeh5': Waiting for transfers to finish 2021/12/01 05:44:58 DEBUG : only1: md5 = 9b8e9a4989fcafa7103bb6f0b5e33358 OK 2021/12/01 05:44:58 INFO : only1: Copied (replaced existing) 2021/12/01 05:44:58 DEBUG : only0: md5 = dabe4226ad8a58a25fba80ab2c9ff7a5 OK 2021/12/01 05:44:58 INFO : only0: Copied (replaced existing) 2021/12/01 05:44:58 DEBUG : only11: md5 = 4d1ac02360f7b9c17f6c9af74334fca8 OK 2021/12/01 05:44:58 INFO : only11: Copied (replaced existing) 2021/12/01 05:44:58 DEBUG : only10: md5 = 27e75b4003f82e3b2bc2ee27a3f75808 OK 2021/12/01 05:44:58 INFO : only10: Copied (replaced existing) 2021/12/01 05:44:59 DEBUG : only12: md5 = 9ca3abd09a66ad9cb7b655c2ee4bfb33 OK 2021/12/01 05:44:59 INFO : only12: Copied (replaced existing) 2021/12/01 05:44:59 DEBUG : only13: md5 = e7711ec89aa062441f85540151594af3 OK 2021/12/01 05:44:59 INFO : only13: Copied (replaced existing) 2021/12/01 05:44:59 DEBUG : only15: md5 = de4d4161a94d5be5052974aa5f2e293c OK 2021/12/01 05:44:59 INFO : only15: Copied (replaced existing) 2021/12/01 05:44:59 DEBUG : only14: md5 = 0b82bd4a5755695335646ceb00fc1834 OK 2021/12/01 05:44:59 INFO : only14: Copied (replaced existing) 2021/12/01 05:45:00 DEBUG : only16: md5 = 5b10e3a4bc26c7112e309760e9dd8b6f OK 2021/12/01 05:45:00 INFO : only16: Copied (replaced existing) 2021/12/01 05:45:00 DEBUG : only17: md5 = 4603a3a22a88080e46f33638ca94ff88 OK 2021/12/01 05:45:00 INFO : only17: Copied (replaced existing) 2021/12/01 05:45:00 DEBUG : only19: md5 = e44baee145c2cfe5c717ceafeee187b8 OK 2021/12/01 05:45:00 INFO : only19: Copied (replaced existing) 2021/12/01 05:45:00 DEBUG : only18: md5 = a0f20075c130068e6aee51ea69aa83f0 OK 2021/12/01 05:45:00 INFO : only18: Copied (replaced existing) 2021/12/01 05:45:01 DEBUG : only4: md5 = 91326147a4ea47f99d59ea58dcdfb3d0 OK 2021/12/01 05:45:01 INFO : only4: Copied (replaced existing) 2021/12/01 05:45:01 DEBUG : only3: md5 = 3cd574c430a7d707c4a1d7e5447b9fb2 OK 2021/12/01 05:45:01 INFO : only3: Copied (replaced existing) 2021/12/01 05:45:02 DEBUG : only2: md5 = b76f7e0c7e948922c6af119b15010ead OK 2021/12/01 05:45:02 INFO : only2: Copied (replaced existing) 2021/12/01 05:45:02 DEBUG : only5: md5 = 6d04f9e86333d4e7a367b7633574f044 OK 2021/12/01 05:45:02 INFO : only5: Copied (replaced existing) 2021/12/01 05:45:03 DEBUG : only6: md5 = 2c3ebbcfc47c38cb5f3c5041e6996349 OK 2021/12/01 05:45:03 INFO : only6: Copied (replaced existing) 2021/12/01 05:45:03 DEBUG : only7: md5 = 10332199dae0edb9e5191d260b494ab9 OK 2021/12/01 05:45:03 INFO : only7: Copied (replaced existing) 2021/12/01 05:45:03 DEBUG : only8: md5 = 11d213823f8d647a0f6aec64ef2c0e7b OK 2021/12/01 05:45:03 INFO : only8: Copied (replaced existing) 2021/12/01 05:45:03 DEBUG : only9: md5 = e334d1a3557d1cac48d9242df095a235 OK 2021/12/01 05:45:03 INFO : only9: Copied (replaced existing) 2021/12/01 05:45:03 DEBUG : Waiting for deletions to finish --- PASS: TestSyncConcurrentTruncate (98.35s) PASS 2021/12/01 05:45:29 DEBUG : Encrypted drive 'TestCryptDrive:rclone-test-beyemut3qobodab0bifemeh5': Purge remote "./sync.test -test.v -test.timeout 1h0m0s -remote TestCryptDrive: -verbose" - Finished OK in 13m56.404359692s (try 1/5)