"./sync.test -test.v -test.timeout 1h0m0s -remote TestB2: -verbose -fast-list" - Starting (try 1/5) === RUN TestPipe --- PASS: TestPipe (0.00s) === RUN TestPipeConcurrent --- PASS: TestPipeConcurrent (0.06s) === 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 --- SKIP: TestRcCopy (0.00s) rc_test.go:16: Skipping test on non local remote === RUN TestRcMove --- SKIP: TestRcMove (0.00s) rc_test.go:16: Skipping test on non local remote === RUN TestRcSync --- SKIP: TestRcSync (0.00s) rc_test.go:16: Skipping test on non local remote === RUN TestCopyWithDryRun 2020/05/15 06:13:27 NOTICE: sub dir/hello world: Not copying as --dry-run 2020/05/15 06:13:27 DEBUG : B2 bucket rclone-test-saruxoz2notuway2wititib9: Waiting for checks to finish 2020/05/15 06:13:27 DEBUG : B2 bucket rclone-test-saruxoz2notuway2wititib9: Waiting for transfers to finish --- PASS: TestCopyWithDryRun (1.37s) run.go:176: Remote "B2 bucket rclone-test-saruxoz2notuway2wititib9", Local "Local file system at /tmp/rclone894978018", Modify Window "1ms" === RUN TestCopy 2020/05/15 06:13:28 DEBUG : B2 bucket rclone-test-saruxoz2notuway2wititib9: Waiting for checks to finish 2020/05/15 06:13:28 DEBUG : B2 bucket rclone-test-saruxoz2notuway2wititib9: Waiting for transfers to finish 2020/05/15 06:13:29 DEBUG : sub dir/hello world: SHA-1 = 2aae6c35c94fcfb415dbe95f408b9ce91ee846ed OK 2020/05/15 06:13:29 INFO : sub dir/hello world: Copied (new) --- PASS: TestCopy (2.23s) run.go:176: Remote "B2 bucket rclone-test-saruxoz2notuway2wititib9", Local "Local file system at /tmp/rclone894978018", Modify Window "1ms" === RUN TestCopyMissingDirectory 2020/05/15 06:13:30 ERROR : : error reading source directory: directory not found 2020/05/15 06:13:30 DEBUG : B2 bucket rclone-test-saruxoz2notuway2wititib9: Waiting for checks to finish 2020/05/15 06:13:30 DEBUG : B2 bucket rclone-test-saruxoz2notuway2wititib9: Waiting for transfers to finish --- PASS: TestCopyMissingDirectory (0.42s) run.go:176: Remote "B2 bucket rclone-test-saruxoz2notuway2wititib9", Local "Local file system at /tmp/rclone894978018", Modify Window "1ms" === RUN TestCopyNoTraverse 2020/05/15 06:13:30 DEBUG : B2 bucket rclone-test-saruxoz2notuway2wititib9: Waiting for checks to finish 2020/05/15 06:13:30 DEBUG : B2 bucket rclone-test-saruxoz2notuway2wititib9: Waiting for transfers to finish 2020/05/15 06:13:31 DEBUG : sub dir/hello world: SHA-1 = 2aae6c35c94fcfb415dbe95f408b9ce91ee846ed OK 2020/05/15 06:13:31 INFO : sub dir/hello world: Copied (new) --- PASS: TestCopyNoTraverse (2.04s) run.go:176: Remote "B2 bucket rclone-test-saruxoz2notuway2wititib9", Local "Local file system at /tmp/rclone894978018", Modify Window "1ms" === RUN TestSyncNoTraverse 2020/05/15 06:13:32 ERROR : Ignoring --no-traverse with sync 2020/05/15 06:13:33 DEBUG : B2 bucket rclone-test-saruxoz2notuway2wititib9: Waiting for checks to finish 2020/05/15 06:13:33 DEBUG : B2 bucket rclone-test-saruxoz2notuway2wititib9: Waiting for transfers to finish 2020/05/15 06:13:33 DEBUG : sub dir/hello world: SHA-1 = 2aae6c35c94fcfb415dbe95f408b9ce91ee846ed OK 2020/05/15 06:13:33 INFO : sub dir/hello world: Copied (new) 2020/05/15 06:13:33 DEBUG : Waiting for deletions to finish --- FAIL: TestSyncNoTraverse (9.13s) run.go:176: Remote "B2 bucket rclone-test-saruxoz2notuway2wititib9", Local "Local file system at /tmp/rclone894978018", Modify Window "1ms" fstest.go:295: Sleeping for 1s for list eventual consistency: 1/3 fstest.go:295: Sleeping for 2s for list eventual consistency: 2/3 fstest.go:295: Sleeping for 4s for list eventual consistency: 3/3 fstest.go:302: Error Trace: fstest.go:302 fstest.go:335 run.go:169 run.go:339 sync_test.go:116 Error: Should be true Test: TestSyncNoTraverse Messages: listing wrong, want got sub dir/hello world (11) fstest.go:188: Error Trace: fstest.go:188 fstest.go:305 fstest.go:335 run.go:169 run.go:339 sync_test.go:116 Error: Should be true Test: TestSyncNoTraverse Messages: Unexpected file "sub dir/hello world" === RUN TestCopyWithDepth 2020/05/15 06:13:42 DEBUG : B2 bucket rclone-test-saruxoz2notuway2wititib9: Waiting for checks to finish 2020/05/15 06:13:42 DEBUG : B2 bucket rclone-test-saruxoz2notuway2wititib9: Waiting for transfers to finish 2020/05/15 06:13:43 DEBUG : hello world2: SHA-1 = c0bf117f9c93d02c894fe8ffd6e5cecf3545c209 OK 2020/05/15 06:13:43 INFO : hello world2: Copied (new) --- FAIL: TestCopyWithDepth (10.46s) run.go:176: Remote "B2 bucket rclone-test-saruxoz2notuway2wititib9", Local "Local file system at /tmp/rclone894978018", Modify Window "1ms" fstest.go:295: Sleeping for 1s for list eventual consistency: 1/3 fstest.go:295: Sleeping for 2s for list eventual consistency: 2/3 fstest.go:295: Sleeping for 4s for list eventual consistency: 3/3 fstest.go:302: Error Trace: fstest.go:302 fstest.go:335 fstest.go:347 sync_test.go:133 Error: Should be true Test: TestCopyWithDepth Messages: listing wrong, want hello world2 (12) got hello world2 (12), sub dir/hello world (11) fstest.go:188: Error Trace: fstest.go:188 fstest.go:305 fstest.go:335 fstest.go:347 sync_test.go:133 Error: Should be true Test: TestCopyWithDepth Messages: Unexpected file "sub dir/hello world" === RUN TestCopyWithFilesFrom 2020/05/15 06:13:52 DEBUG : hello world2: Excluded 2020/05/15 06:13:52 DEBUG : B2 bucket rclone-test-saruxoz2notuway2wititib9: Waiting for checks to finish 2020/05/15 06:13:52 DEBUG : B2 bucket rclone-test-saruxoz2notuway2wititib9: Waiting for transfers to finish 2020/05/15 06:13:56 DEBUG : potato2: SHA-1 = 2aae6c35c94fcfb415dbe95f408b9ce91ee846ed OK 2020/05/15 06:13:56 INFO : potato2: Copied (new) --- PASS: TestCopyWithFilesFrom (4.78s) run.go:176: Remote "B2 bucket rclone-test-saruxoz2notuway2wititib9", Local "Local file system at /tmp/rclone894978018", Modify Window "1ms" === RUN TestCopyWithFilesFromAndNoTraverse 2020/05/15 06:13:57 DEBUG : B2 bucket rclone-test-saruxoz2notuway2wititib9: Waiting for checks to finish 2020/05/15 06:13:57 DEBUG : B2 bucket rclone-test-saruxoz2notuway2wititib9: Waiting for transfers to finish 2020/05/15 06:13:58 DEBUG : potato2: SHA-1 = 2aae6c35c94fcfb415dbe95f408b9ce91ee846ed OK 2020/05/15 06:13:58 INFO : potato2: Copied (new) --- PASS: TestCopyWithFilesFromAndNoTraverse (1.89s) run.go:176: Remote "B2 bucket rclone-test-saruxoz2notuway2wititib9", Local "Local file system at /tmp/rclone894978018", Modify Window "1ms" === RUN TestCopyEmptyDirectories 2020/05/15 06:13:59 DEBUG : sub dir2: Making directory 2020/05/15 06:13:59 DEBUG : B2 bucket rclone-test-saruxoz2notuway2wititib9: Waiting for checks to finish 2020/05/15 06:13:59 DEBUG : B2 bucket rclone-test-saruxoz2notuway2wititib9: Waiting for transfers to finish 2020/05/15 06:13:59 DEBUG : sub dir/hello world: SHA-1 = 2aae6c35c94fcfb415dbe95f408b9ce91ee846ed OK 2020/05/15 06:13:59 INFO : sub dir/hello world: Copied (new) 2020/05/15 06:13:59 DEBUG : sub dir2: Making directory 2020/05/15 06:13:59 DEBUG : B2 bucket rclone-test-saruxoz2notuway2wititib9: copied 1 directories --- PASS: TestCopyEmptyDirectories (1.95s) run.go:176: Remote "B2 bucket rclone-test-saruxoz2notuway2wititib9", Local "Local file system at /tmp/rclone894978018", Modify Window "1ms" fstest.go:247: Filtering empty directory "sub dir2" === RUN TestMoveEmptyDirectories 2020/05/15 06:14:01 DEBUG : sub dir2: Making directory 2020/05/15 06:14:01 DEBUG : B2 bucket rclone-test-saruxoz2notuway2wititib9: Waiting for checks to finish 2020/05/15 06:14:01 DEBUG : B2 bucket rclone-test-saruxoz2notuway2wititib9: Waiting for transfers to finish 2020/05/15 06:14:01 DEBUG : sub dir/hello world: SHA-1 = 2aae6c35c94fcfb415dbe95f408b9ce91ee846ed OK 2020/05/15 06:14:01 INFO : sub dir/hello world: Copied (new) 2020/05/15 06:14:01 INFO : sub dir/hello world: Deleted 2020/05/15 06:14:01 DEBUG : sub dir2: Making directory 2020/05/15 06:14:01 DEBUG : sub dir: Making directory 2020/05/15 06:14:01 DEBUG : B2 bucket rclone-test-saruxoz2notuway2wititib9: copied 2 directories --- PASS: TestMoveEmptyDirectories (1.59s) run.go:176: Remote "B2 bucket rclone-test-saruxoz2notuway2wititib9", Local "Local file system at /tmp/rclone894978018", Modify Window "1ms" fstest.go:247: Filtering empty directory "sub dir2" === RUN TestSyncEmptyDirectories 2020/05/15 06:14:02 DEBUG : sub dir2: Making directory 2020/05/15 06:14:02 DEBUG : B2 bucket rclone-test-saruxoz2notuway2wititib9: Waiting for checks to finish 2020/05/15 06:14:02 DEBUG : B2 bucket rclone-test-saruxoz2notuway2wititib9: Waiting for transfers to finish 2020/05/15 06:14:03 DEBUG : sub dir/hello world: SHA-1 = 2aae6c35c94fcfb415dbe95f408b9ce91ee846ed OK 2020/05/15 06:14:03 INFO : sub dir/hello world: Copied (new) 2020/05/15 06:14:03 DEBUG : sub dir2: Making directory 2020/05/15 06:14:03 DEBUG : B2 bucket rclone-test-saruxoz2notuway2wititib9: copied 1 directories 2020/05/15 06:14:03 DEBUG : Waiting for deletions to finish --- PASS: TestSyncEmptyDirectories (2.48s) run.go:176: Remote "B2 bucket rclone-test-saruxoz2notuway2wititib9", Local "Local file system at /tmp/rclone894978018", Modify Window "1ms" fstest.go:247: Filtering empty directory "sub dir2" === RUN TestServerSideCopy 2020/05/15 06:14:06 DEBUG : B2 bucket rclone-test-wosafok4homivan3quvapaw2: Waiting for checks to finish 2020/05/15 06:14:06 DEBUG : B2 bucket rclone-test-wosafok4homivan3quvapaw2: Waiting for transfers to finish 2020/05/15 06:14:09 DEBUG : sub dir/hello world: SHA-1 = 2aae6c35c94fcfb415dbe95f408b9ce91ee846ed OK 2020/05/15 06:14:09 INFO : sub dir/hello world: Copied (server side copy) 2020/05/15 06:14:09 DEBUG : B2 bucket rclone-test-wosafok4homivan3quvapaw2: Purge remote 2020/05/15 06:14:09 DEBUG : sub dir/hello world: Deleting (id "4_z8fd2ede3f07d1b6b7f280e1b_f107b2a0e7ea35ec3_d20200515_m061407_c001_v0001092_t0059") --- PASS: TestServerSideCopy (6.40s) run.go:176: Remote "B2 bucket rclone-test-saruxoz2notuway2wititib9", Local "Local file system at /tmp/rclone894978018", Modify Window "1ms" sync_test.go:258: Server side copy (if possible) B2 bucket rclone-test-saruxoz2notuway2wititib9 -> B2 bucket rclone-test-wosafok4homivan3quvapaw2 === RUN TestCopyAfterDelete 2020/05/15 06:14:13 ERROR : : error listing: directory not found 2020/05/15 06:14:13 DEBUG : Local file system at /tmp/rclone894978018: Making directory 2020/05/15 06:14:13 DEBUG : B2 bucket rclone-test-saruxoz2notuway2wititib9: Waiting for checks to finish 2020/05/15 06:14:13 DEBUG : B2 bucket rclone-test-saruxoz2notuway2wititib9: Waiting for transfers to finish --- PASS: TestCopyAfterDelete (2.39s) run.go:176: Remote "B2 bucket rclone-test-saruxoz2notuway2wititib9", Local "Local file system at /tmp/rclone894978018", Modify Window "1ms" === RUN TestCopyRedownload 2020/05/15 06:14:15 DEBUG : Local file system at /tmp/rclone894978018: Waiting for checks to finish 2020/05/15 06:14:15 DEBUG : Local file system at /tmp/rclone894978018: Waiting for transfers to finish 2020/05/15 06:14:15 DEBUG : sub dir/hello world: SHA-1 = 2aae6c35c94fcfb415dbe95f408b9ce91ee846ed OK 2020/05/15 06:14:15 INFO : sub dir/hello world: Copied (new) --- PASS: TestCopyRedownload (2.75s) run.go:176: Remote "B2 bucket rclone-test-saruxoz2notuway2wititib9", Local "Local file system at /tmp/rclone894978018", Modify Window "1ms" === RUN TestSyncBasedOnCheckSum 2020/05/15 06:14:16 DEBUG : B2 bucket rclone-test-saruxoz2notuway2wititib9: Waiting for checks to finish 2020/05/15 06:14:16 DEBUG : B2 bucket rclone-test-saruxoz2notuway2wititib9: Waiting for transfers to finish 2020/05/15 06:14:17 DEBUG : check sum: SHA-1 = 3bc15c8aae3e4124dd409035f32ea2fd6835efc9 OK 2020/05/15 06:14:17 INFO : check sum: Copied (new) 2020/05/15 06:14:17 DEBUG : Waiting for deletions to finish 2020/05/15 06:14:17 DEBUG : B2 bucket rclone-test-saruxoz2notuway2wititib9: Waiting for checks to finish 2020/05/15 06:14:17 DEBUG : check sum: SHA-1 = 3bc15c8aae3e4124dd409035f32ea2fd6835efc9 OK 2020/05/15 06:14:17 DEBUG : check sum: Size and SHA-1 of src and dst objects identical 2020/05/15 06:14:17 DEBUG : check sum: Unchanged skipping 2020/05/15 06:14:17 DEBUG : B2 bucket rclone-test-saruxoz2notuway2wititib9: Waiting for transfers to finish 2020/05/15 06:14:17 DEBUG : Waiting for deletions to finish 2020/05/15 06:14:17 INFO : There was nothing to transfer --- PASS: TestSyncBasedOnCheckSum (1.86s) run.go:176: Remote "B2 bucket rclone-test-saruxoz2notuway2wititib9", Local "Local file system at /tmp/rclone894978018", Modify Window "1ms" === RUN TestSyncSizeOnly 2020/05/15 06:14:18 DEBUG : B2 bucket rclone-test-saruxoz2notuway2wititib9: Waiting for checks to finish 2020/05/15 06:14:18 DEBUG : B2 bucket rclone-test-saruxoz2notuway2wititib9: Waiting for transfers to finish 2020/05/15 06:14:18 DEBUG : sizeonly: SHA-1 = 3e2e95f5ad970eadfa7e17eaf73da97024aa5359 OK 2020/05/15 06:14:18 INFO : sizeonly: Copied (new) 2020/05/15 06:14:18 DEBUG : Waiting for deletions to finish 2020/05/15 06:14:19 DEBUG : sizeonly: Sizes identical 2020/05/15 06:14:19 DEBUG : sizeonly: Unchanged skipping 2020/05/15 06:14:19 DEBUG : B2 bucket rclone-test-saruxoz2notuway2wititib9: Waiting for checks to finish 2020/05/15 06:14:19 DEBUG : B2 bucket rclone-test-saruxoz2notuway2wititib9: Waiting for transfers to finish 2020/05/15 06:14:19 DEBUG : Waiting for deletions to finish 2020/05/15 06:14:19 INFO : There was nothing to transfer --- PASS: TestSyncSizeOnly (1.63s) run.go:176: Remote "B2 bucket rclone-test-saruxoz2notuway2wititib9", Local "Local file system at /tmp/rclone894978018", Modify Window "1ms" === RUN TestSyncIgnoreSize 2020/05/15 06:14:20 DEBUG : B2 bucket rclone-test-saruxoz2notuway2wititib9: Waiting for checks to finish 2020/05/15 06:14:20 DEBUG : B2 bucket rclone-test-saruxoz2notuway2wititib9: Waiting for transfers to finish 2020/05/15 06:14:20 DEBUG : ignore-size: SHA-1 = 4a756ca07e9487f482465a99e8286abc86ba4dc7 OK 2020/05/15 06:14:20 INFO : ignore-size: Copied (new) 2020/05/15 06:14:20 DEBUG : Waiting for deletions to finish 2020/05/15 06:14:21 DEBUG : ignore-size: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2020/05/15 06:14:21 DEBUG : ignore-size: Unchanged skipping 2020/05/15 06:14:21 DEBUG : B2 bucket rclone-test-saruxoz2notuway2wititib9: Waiting for checks to finish 2020/05/15 06:14:21 DEBUG : B2 bucket rclone-test-saruxoz2notuway2wititib9: Waiting for transfers to finish 2020/05/15 06:14:21 DEBUG : Waiting for deletions to finish 2020/05/15 06:14:21 INFO : There was nothing to transfer --- PASS: TestSyncIgnoreSize (1.64s) run.go:176: Remote "B2 bucket rclone-test-saruxoz2notuway2wititib9", Local "Local file system at /tmp/rclone894978018", Modify Window "1ms" === RUN TestSyncIgnoreTimes 2020/05/15 06:14:22 DEBUG : B2 bucket rclone-test-saruxoz2notuway2wititib9: Waiting for checks to finish 2020/05/15 06:14:22 DEBUG : existing: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2020/05/15 06:14:22 DEBUG : existing: Unchanged skipping 2020/05/15 06:14:22 DEBUG : B2 bucket rclone-test-saruxoz2notuway2wititib9: Waiting for transfers to finish 2020/05/15 06:14:22 DEBUG : Waiting for deletions to finish 2020/05/15 06:14:22 INFO : There was nothing to transfer 2020/05/15 06:14:23 DEBUG : B2 bucket rclone-test-saruxoz2notuway2wititib9: Waiting for checks to finish 2020/05/15 06:14:23 DEBUG : existing: Transferring unconditionally as --ignore-times is in use 2020/05/15 06:14:23 DEBUG : B2 bucket rclone-test-saruxoz2notuway2wititib9: Waiting for transfers to finish 2020/05/15 06:14:23 DEBUG : existing: SHA-1 = 3e2e95f5ad970eadfa7e17eaf73da97024aa5359 OK 2020/05/15 06:14:23 INFO : existing: Copied (replaced existing) 2020/05/15 06:14:23 DEBUG : Waiting for deletions to finish --- FAIL: TestSyncIgnoreTimes (10.00s) run.go:176: Remote "B2 bucket rclone-test-saruxoz2notuway2wititib9", Local "Local file system at /tmp/rclone894978018", Modify Window "1ms" fstest.go:295: Sleeping for 1s for list eventual consistency: 1/3 fstest.go:295: Sleeping for 2s for list eventual consistency: 2/3 fstest.go:295: Sleeping for 4s for list eventual consistency: 3/3 fstest.go:302: Error Trace: fstest.go:302 fstest.go:335 run.go:169 run.go:339 sync_test.go:428 Error: Should be true Test: TestSyncIgnoreTimes Messages: listing wrong, want got existing (6) fstest.go:188: Error Trace: fstest.go:188 fstest.go:305 fstest.go:335 run.go:169 run.go:339 sync_test.go:428 Error: Should be true Test: TestSyncIgnoreTimes Messages: Unexpected file "existing" === RUN TestSyncIgnoreExisting 2020/05/15 06:14:31 DEBUG : existing: Destination exists, skipping 2020/05/15 06:14:31 DEBUG : B2 bucket rclone-test-saruxoz2notuway2wititib9: Waiting for checks to finish 2020/05/15 06:14:31 DEBUG : B2 bucket rclone-test-saruxoz2notuway2wititib9: Waiting for transfers to finish 2020/05/15 06:14:31 DEBUG : Waiting for deletions to finish 2020/05/15 06:14:31 INFO : There was nothing to transfer 2020/05/15 06:14:32 DEBUG : existing: Destination exists, skipping 2020/05/15 06:14:32 DEBUG : B2 bucket rclone-test-saruxoz2notuway2wititib9: Waiting for checks to finish 2020/05/15 06:14:32 DEBUG : B2 bucket rclone-test-saruxoz2notuway2wititib9: Waiting for transfers to finish 2020/05/15 06:14:32 DEBUG : Waiting for deletions to finish 2020/05/15 06:14:32 INFO : There was nothing to transfer --- PASS: TestSyncIgnoreExisting (1.46s) run.go:176: Remote "B2 bucket rclone-test-saruxoz2notuway2wititib9", Local "Local file system at /tmp/rclone894978018", Modify Window "1ms" === RUN TestSyncIgnoreErrors 2020/05/15 06:14:34 DEBUG : d: Making directory 2020/05/15 06:14:35 DEBUG : c/non empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2020/05/15 06:14:35 DEBUG : c/non empty space: Unchanged skipping 2020/05/15 06:14:35 DEBUG : B2 bucket rclone-test-saruxoz2notuway2wititib9: Waiting for checks to finish 2020/05/15 06:14:35 DEBUG : B2 bucket rclone-test-saruxoz2notuway2wititib9: Waiting for transfers to finish 2020/05/15 06:14:35 DEBUG : a/potato2: SHA-1 = 9dc7f7d3279715991a22853f5981df582b7f9f6d OK 2020/05/15 06:14:35 INFO : a/potato2: Copied (new) 2020/05/15 06:14:35 DEBUG : Waiting for deletions to finish 2020/05/15 06:14:36 INFO : b/potato: Deleted --- PASS: TestSyncIgnoreErrors (4.63s) run.go:176: Remote "B2 bucket rclone-test-saruxoz2notuway2wititib9", Local "Local file system at /tmp/rclone894978018", Modify Window "1ms" fstest.go:247: Filtering empty directory "d" === RUN TestSyncAfterChangingModtimeOnly 2020/05/15 06:14:38 DEBUG : B2 bucket rclone-test-saruxoz2notuway2wititib9: Waiting for checks to finish 2020/05/15 06:14:38 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 2020/05/15 06:14:38 DEBUG : empty space: SHA-1 = 3bc15c8aae3e4124dd409035f32ea2fd6835efc9 OK 2020/05/15 06:14:38 NOTICE: empty space: Not updating modification time as --dry-run 2020/05/15 06:14:38 DEBUG : empty space: Unchanged skipping 2020/05/15 06:14:38 DEBUG : B2 bucket rclone-test-saruxoz2notuway2wititib9: Waiting for transfers to finish 2020/05/15 06:14:38 DEBUG : Waiting for deletions to finish 2020/05/15 06:14:38 INFO : There was nothing to transfer 2020/05/15 06:14:38 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 2020/05/15 06:14:38 DEBUG : B2 bucket rclone-test-saruxoz2notuway2wititib9: Waiting for checks to finish 2020/05/15 06:14:38 DEBUG : empty space: SHA-1 = 3bc15c8aae3e4124dd409035f32ea2fd6835efc9 OK 2020/05/15 06:14:39 INFO : empty space: Updated modification time in destination 2020/05/15 06:14:39 DEBUG : empty space: Unchanged skipping 2020/05/15 06:14:39 DEBUG : B2 bucket rclone-test-saruxoz2notuway2wititib9: Waiting for transfers to finish 2020/05/15 06:14:39 DEBUG : Waiting for deletions to finish 2020/05/15 06:14:39 INFO : There was nothing to transfer --- FAIL: TestSyncAfterChangingModtimeOnly (10.17s) run.go:176: Remote "B2 bucket rclone-test-saruxoz2notuway2wititib9", Local "Local file system at /tmp/rclone894978018", Modify Window "1ms" fstest.go:295: Sleeping for 1s for list eventual consistency: 1/3 fstest.go:295: Sleeping for 2s for list eventual consistency: 2/3 fstest.go:295: Sleeping for 4s for list eventual consistency: 3/3 fstest.go:302: Error Trace: fstest.go:302 fstest.go:335 run.go:169 run.go:339 sync_test.go:552 Error: Should be true Test: TestSyncAfterChangingModtimeOnly Messages: listing wrong, want got empty space (1) fstest.go:188: Error Trace: fstest.go:188 fstest.go:305 fstest.go:335 run.go:169 run.go:339 sync_test.go:552 Error: Should be true Test: TestSyncAfterChangingModtimeOnly Messages: Unexpected file "empty space" === RUN TestSyncAfterChangingModtimeOnlyWithNoUpdateModTime 2020/05/15 06:14:49 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 2020/05/15 06:14:49 DEBUG : B2 bucket rclone-test-saruxoz2notuway2wititib9: Waiting for checks to finish 2020/05/15 06:14:49 DEBUG : empty space: SHA-1 = 3bc15c8aae3e4124dd409035f32ea2fd6835efc9 OK 2020/05/15 06:14:49 DEBUG : empty space: Unchanged skipping 2020/05/15 06:14:49 DEBUG : B2 bucket rclone-test-saruxoz2notuway2wititib9: Waiting for transfers to finish 2020/05/15 06:14:49 DEBUG : Waiting for deletions to finish 2020/05/15 06:14:49 INFO : There was nothing to transfer --- PASS: TestSyncAfterChangingModtimeOnlyWithNoUpdateModTime (2.61s) run.go:176: Remote "B2 bucket rclone-test-saruxoz2notuway2wititib9", Local "Local file system at /tmp/rclone894978018", Modify Window "1ms" === RUN TestSyncDoesntUpdateModtime 2020/05/15 06:14:52 DEBUG : foo: Modification times differ by -95456h54m52.624456789s: 2011-12-25 12:59:59.123456789 +0000 UTC, 2001-02-03 04:05:06.499 +0000 UTC 2020/05/15 06:14:52 DEBUG : B2 bucket rclone-test-saruxoz2notuway2wititib9: Waiting for checks to finish 2020/05/15 06:14:52 DEBUG : foo: SHA-1 = 0beec7b5ea3f0fdbc95d0dd47f3c5bc275da8a33 (Local file system at /tmp/rclone894978018) 2020/05/15 06:14:52 DEBUG : foo: SHA-1 = 62cdb7020ff920e5aa642c3d4066950dd1f01f4d (B2 bucket rclone-test-saruxoz2notuway2wititib9) 2020/05/15 06:14:52 DEBUG : foo: SHA-1 differ 2020/05/15 06:14:52 DEBUG : B2 bucket rclone-test-saruxoz2notuway2wititib9: Waiting for transfers to finish 2020/05/15 06:14:57 DEBUG : foo: SHA-1 = 0beec7b5ea3f0fdbc95d0dd47f3c5bc275da8a33 OK 2020/05/15 06:14:57 INFO : foo: Copied (replaced existing) 2020/05/15 06:14:57 DEBUG : Waiting for deletions to finish --- PASS: TestSyncDoesntUpdateModtime (7.58s) run.go:176: Remote "B2 bucket rclone-test-saruxoz2notuway2wititib9", Local "Local file system at /tmp/rclone894978018", Modify Window "1ms" === RUN TestSyncAfterAddingAFile 2020/05/15 06:14:59 DEBUG : B2 bucket rclone-test-saruxoz2notuway2wititib9: Waiting for checks to finish 2020/05/15 06:14:59 DEBUG : empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2020/05/15 06:14:59 DEBUG : empty space: Unchanged skipping 2020/05/15 06:14:59 DEBUG : B2 bucket rclone-test-saruxoz2notuway2wititib9: Waiting for transfers to finish 2020/05/15 06:15:00 DEBUG : potato: SHA-1 = 9dc7f7d3279715991a22853f5981df582b7f9f6d OK 2020/05/15 06:15:00 INFO : potato: Copied (new) 2020/05/15 06:15:00 DEBUG : Waiting for deletions to finish --- PASS: TestSyncAfterAddingAFile (3.77s) run.go:176: Remote "B2 bucket rclone-test-saruxoz2notuway2wititib9", Local "Local file system at /tmp/rclone894978018", Modify Window "1ms" === RUN TestSyncAfterChangingFilesSizeOnly 2020/05/15 06:15:03 DEBUG : potato: Sizes differ (src 21 vs dst 60) 2020/05/15 06:15:03 DEBUG : B2 bucket rclone-test-saruxoz2notuway2wititib9: Waiting for checks to finish 2020/05/15 06:15:03 DEBUG : B2 bucket rclone-test-saruxoz2notuway2wititib9: Waiting for transfers to finish 2020/05/15 06:15:04 DEBUG : potato: SHA-1 = 0fd321a1023ac4e1e1054fcc0236b9d0755f722f OK 2020/05/15 06:15:04 INFO : potato: Copied (replaced existing) 2020/05/15 06:15:04 DEBUG : Waiting for deletions to finish --- PASS: TestSyncAfterChangingFilesSizeOnly (3.42s) run.go:176: Remote "B2 bucket rclone-test-saruxoz2notuway2wititib9", Local "Local file system at /tmp/rclone894978018", Modify Window "1ms" === RUN TestSyncAfterChangingContentsOnly 2020/05/15 06:15:06 DEBUG : B2 bucket rclone-test-saruxoz2notuway2wititib9: Waiting for checks to finish 2020/05/15 06:15:06 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 2020/05/15 06:15:06 DEBUG : potato: SHA-1 = 1ca5094b3b73f587249eabe179c40a3eec839b1f (Local file system at /tmp/rclone894978018) 2020/05/15 06:15:06 DEBUG : potato: SHA-1 = 0fd321a1023ac4e1e1054fcc0236b9d0755f722f (B2 bucket rclone-test-saruxoz2notuway2wititib9) 2020/05/15 06:15:06 DEBUG : potato: SHA-1 differ 2020/05/15 06:15:06 DEBUG : B2 bucket rclone-test-saruxoz2notuway2wititib9: Waiting for transfers to finish 2020/05/15 06:15:07 DEBUG : potato: SHA-1 = 1ca5094b3b73f587249eabe179c40a3eec839b1f OK 2020/05/15 06:15:07 INFO : potato: Copied (replaced existing) 2020/05/15 06:15:07 DEBUG : Waiting for deletions to finish --- PASS: TestSyncAfterChangingContentsOnly (2.60s) run.go:176: Remote "B2 bucket rclone-test-saruxoz2notuway2wititib9", Local "Local file system at /tmp/rclone894978018", Modify Window "1ms" === RUN TestSyncAfterRemovingAFileAndAddingAFileDryRun 2020/05/15 06:15:09 NOTICE: potato2: Not copying as --dry-run 2020/05/15 06:15:09 DEBUG : B2 bucket rclone-test-saruxoz2notuway2wititib9: Waiting for checks to finish 2020/05/15 06:15:09 DEBUG : empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2020/05/15 06:15:09 DEBUG : empty space: Unchanged skipping 2020/05/15 06:15:09 DEBUG : B2 bucket rclone-test-saruxoz2notuway2wititib9: Waiting for transfers to finish 2020/05/15 06:15:09 DEBUG : Waiting for deletions to finish 2020/05/15 06:15:09 NOTICE: potato: Not deleting as --dry-run --- PASS: TestSyncAfterRemovingAFileAndAddingAFileDryRun (5.25s) run.go:176: Remote "B2 bucket rclone-test-saruxoz2notuway2wititib9", Local "Local file system at /tmp/rclone894978018", Modify Window "1ms" === RUN TestSyncAfterRemovingAFileAndAddingAFile 2020/05/15 06:15:14 DEBUG : empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2020/05/15 06:15:14 DEBUG : empty space: Unchanged skipping 2020/05/15 06:15:14 DEBUG : B2 bucket rclone-test-saruxoz2notuway2wititib9: Waiting for checks to finish 2020/05/15 06:15:14 DEBUG : B2 bucket rclone-test-saruxoz2notuway2wititib9: Waiting for transfers to finish 2020/05/15 06:15:15 DEBUG : potato2: SHA-1 = 9dc7f7d3279715991a22853f5981df582b7f9f6d OK 2020/05/15 06:15:15 INFO : potato2: Copied (new) 2020/05/15 06:15:15 DEBUG : Waiting for deletions to finish 2020/05/15 06:15:15 INFO : potato: Deleted --- PASS: TestSyncAfterRemovingAFileAndAddingAFile (4.72s) run.go:176: Remote "B2 bucket rclone-test-saruxoz2notuway2wititib9", Local "Local file system at /tmp/rclone894978018", Modify Window "1ms" === RUN TestSyncAfterRemovingAFileAndAddingAFileSubDir 2020/05/15 06:15:19 DEBUG : d: Making directory 2020/05/15 06:15:19 DEBUG : d/e: Making directory 2020/05/15 06:15:19 DEBUG : B2 bucket rclone-test-saruxoz2notuway2wititib9: Waiting for checks to finish 2020/05/15 06:15:19 DEBUG : c/non empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2020/05/15 06:15:19 DEBUG : c/non empty space: Unchanged skipping 2020/05/15 06:15:19 DEBUG : B2 bucket rclone-test-saruxoz2notuway2wititib9: Waiting for transfers to finish 2020/05/15 06:15:20 DEBUG : a/potato2: SHA-1 = 9dc7f7d3279715991a22853f5981df582b7f9f6d OK 2020/05/15 06:15:20 INFO : a/potato2: Copied (new) 2020/05/15 06:15:20 DEBUG : Waiting for deletions to finish 2020/05/15 06:15:20 INFO : b/potato: Deleted --- PASS: TestSyncAfterRemovingAFileAndAddingAFileSubDir (4.30s) run.go:176: Remote "B2 bucket rclone-test-saruxoz2notuway2wititib9", Local "Local file system at /tmp/rclone894978018", Modify Window "1ms" fstest.go:247: Filtering empty directory "d" fstest.go:247: Filtering empty directory "d/e" === RUN TestSyncAfterRemovingAFileAndAddingAFileSubDirWithErrors 2020/05/15 06:15:23 DEBUG : d: Making directory 2020/05/15 06:15:23 DEBUG : B2 bucket rclone-test-saruxoz2notuway2wititib9: Waiting for checks to finish 2020/05/15 06:15:23 DEBUG : c/non empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2020/05/15 06:15:23 DEBUG : c/non empty space: Unchanged skipping 2020/05/15 06:15:23 DEBUG : B2 bucket rclone-test-saruxoz2notuway2wititib9: Waiting for transfers to finish 2020/05/15 06:15:24 DEBUG : a/potato2: SHA-1 = 9dc7f7d3279715991a22853f5981df582b7f9f6d OK 2020/05/15 06:15:24 INFO : a/potato2: Copied (new) 2020/05/15 06:15:24 ERROR : B2 bucket rclone-test-saruxoz2notuway2wititib9: not deleting files as there were IO errors 2020/05/15 06:15:24 ERROR : B2 bucket rclone-test-saruxoz2notuway2wititib9: not deleting directories as there were IO errors --- FAIL: TestSyncAfterRemovingAFileAndAddingAFileSubDirWithErrors (11.47s) run.go:176: Remote "B2 bucket rclone-test-saruxoz2notuway2wititib9", Local "Local file system at /tmp/rclone894978018", Modify Window "1ms" fstest.go:247: Filtering empty directory "d" fstest.go:247: Filtering empty directory "d" fstest.go:295: Sleeping for 1s for list eventual consistency: 1/3 fstest.go:295: Sleeping for 2s for list eventual consistency: 2/3 fstest.go:295: Sleeping for 4s for list eventual consistency: 3/3 fstest.go:302: Error Trace: fstest.go:302 fstest.go:335 run.go:169 run.go:339 sync_test.go:837 Error: Should be true Test: TestSyncAfterRemovingAFileAndAddingAFileSubDirWithErrors Messages: listing wrong, want got a/potato2 (60) fstest.go:188: Error Trace: fstest.go:188 fstest.go:305 fstest.go:335 run.go:169 run.go:339 sync_test.go:837 Error: Should be true Test: TestSyncAfterRemovingAFileAndAddingAFileSubDirWithErrors Messages: Unexpected file "a/potato2" === RUN TestSyncDeleteAfter --- PASS: TestSyncDeleteAfter (0.00s) === RUN TestSyncDeleteDuring 2020/05/15 06:15:43 DEBUG : Waiting for deletions to finish 2020/05/15 06:15:43 DEBUG : empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2020/05/15 06:15:43 DEBUG : empty space: Unchanged skipping 2020/05/15 06:15:43 DEBUG : B2 bucket rclone-test-saruxoz2notuway2wititib9: Waiting for checks to finish 2020/05/15 06:15:43 DEBUG : B2 bucket rclone-test-saruxoz2notuway2wititib9: Waiting for transfers to finish 2020/05/15 06:15:43 INFO : potato: Deleted 2020/05/15 06:15:44 DEBUG : potato2: SHA-1 = 9dc7f7d3279715991a22853f5981df582b7f9f6d OK 2020/05/15 06:15:44 INFO : potato2: Copied (new) 2020/05/15 06:15:44 INFO : a/potato2: Deleted --- FAIL: TestSyncDeleteDuring (12.35s) run.go:176: Remote "B2 bucket rclone-test-saruxoz2notuway2wititib9", Local "Local file system at /tmp/rclone894978018", Modify Window "1ms" fstest.go:295: Sleeping for 1s for list eventual consistency: 1/3 fstest.go:295: Sleeping for 2s for list eventual consistency: 2/3 fstest.go:295: Sleeping for 4s for list eventual consistency: 3/3 fstest.go:302: Error Trace: fstest.go:302 fstest.go:335 fstest.go:347 sync_test.go:685 Error: Should be true Test: TestSyncDeleteDuring Messages: listing wrong, want empty space (1), potato (21) got a/potato2 (60), empty space (1), potato (21) fstest.go:188: Error Trace: fstest.go:188 fstest.go:305 fstest.go:335 fstest.go:347 sync_test.go:685 Error: Should be true Test: TestSyncDeleteDuring Messages: Unexpected file "a/potato2" === RUN TestSyncDeleteBefore 2020/05/15 06:15:49 DEBUG : Waiting for deletions to finish 2020/05/15 06:15:49 DEBUG : B2 bucket rclone-test-saruxoz2notuway2wititib9: Waiting for checks to finish 2020/05/15 06:15:49 DEBUG : B2 bucket rclone-test-saruxoz2notuway2wititib9: Waiting for transfers to finish 2020/05/15 06:15:49 INFO : potato: Deleted 2020/05/15 06:15:50 DEBUG : empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2020/05/15 06:15:50 DEBUG : empty space: Unchanged skipping 2020/05/15 06:15:50 DEBUG : B2 bucket rclone-test-saruxoz2notuway2wititib9: Waiting for checks to finish 2020/05/15 06:15:50 DEBUG : B2 bucket rclone-test-saruxoz2notuway2wititib9: Waiting for transfers to finish 2020/05/15 06:15:50 DEBUG : potato2: SHA-1 = 9dc7f7d3279715991a22853f5981df582b7f9f6d OK 2020/05/15 06:15:50 INFO : potato2: Copied (new) --- PASS: TestSyncDeleteBefore (6.59s) run.go:176: Remote "B2 bucket rclone-test-saruxoz2notuway2wititib9", Local "Local file system at /tmp/rclone894978018", Modify Window "1ms" === RUN TestCopyDeleteBefore 2020/05/15 06:16:00 DEBUG : B2 bucket rclone-test-saruxoz2notuway2wititib9: Waiting for checks to finish 2020/05/15 06:16:00 DEBUG : B2 bucket rclone-test-saruxoz2notuway2wititib9: Waiting for transfers to finish 2020/05/15 06:16:07 DEBUG : potato2: SHA-1 = 810274f0df19dab60a894a562b7a8ff04c072623 OK 2020/05/15 06:16:07 INFO : potato2: Copied (new) --- PASS: TestCopyDeleteBefore (17.54s) run.go:176: Remote "B2 bucket rclone-test-saruxoz2notuway2wititib9", Local "Local file system at /tmp/rclone894978018", Modify Window "1ms" === RUN TestSyncWithExclude 2020/05/15 06:16:14 DEBUG : potato2: Excluded 2020/05/15 06:16:14 DEBUG : enormous: Excluded 2020/05/15 06:16:14 DEBUG : potato2: Excluded from sync (and deletion) 2020/05/15 06:16:14 DEBUG : empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2020/05/15 06:16:14 DEBUG : empty space: Unchanged skipping 2020/05/15 06:16:14 DEBUG : B2 bucket rclone-test-saruxoz2notuway2wititib9: Waiting for checks to finish 2020/05/15 06:16:14 DEBUG : B2 bucket rclone-test-saruxoz2notuway2wititib9: Waiting for transfers to finish 2020/05/15 06:16:14 DEBUG : Waiting for deletions to finish 2020/05/15 06:16:14 INFO : There was nothing to transfer 2020/05/15 06:16:14 DEBUG : potato2: Excluded 2020/05/15 06:16:14 DEBUG : enormous: Excluded 2020/05/15 06:16:14 DEBUG : potato2: Excluded from sync (and deletion) 2020/05/15 06:16:14 DEBUG : Local file system at /tmp/rclone894978018: Waiting for checks to finish 2020/05/15 06:16:14 DEBUG : empty space: Size and modification time the same (differ by 456.789µs, within tolerance 1ms) 2020/05/15 06:16:14 DEBUG : empty space: Unchanged skipping 2020/05/15 06:16:14 DEBUG : Local file system at /tmp/rclone894978018: Waiting for transfers to finish 2020/05/15 06:16:14 DEBUG : Waiting for deletions to finish 2020/05/15 06:16:14 INFO : There was nothing to transfer --- PASS: TestSyncWithExclude (6.55s) run.go:176: Remote "B2 bucket rclone-test-saruxoz2notuway2wititib9", Local "Local file system at /tmp/rclone894978018", Modify Window "1ms" === RUN TestSyncWithExcludeAndDeleteExcluded 2020/05/15 06:16:21 DEBUG : potato2: Excluded 2020/05/15 06:16:21 DEBUG : enormous: Excluded 2020/05/15 06:16:21 DEBUG : B2 bucket rclone-test-saruxoz2notuway2wititib9: Waiting for checks to finish 2020/05/15 06:16:21 DEBUG : empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2020/05/15 06:16:21 DEBUG : empty space: Unchanged skipping 2020/05/15 06:16:21 DEBUG : B2 bucket rclone-test-saruxoz2notuway2wititib9: Waiting for transfers to finish 2020/05/15 06:16:21 DEBUG : Waiting for deletions to finish 2020/05/15 06:16:22 INFO : enormous: Deleted 2020/05/15 06:16:22 INFO : potato2: Deleted 2020/05/15 06:16:22 INFO : There was nothing to transfer 2020/05/15 06:16:22 DEBUG : empty space: Size and modification time the same (differ by 456.789µs, within tolerance 1ms) 2020/05/15 06:16:22 DEBUG : empty space: Unchanged skipping 2020/05/15 06:16:22 DEBUG : Local file system at /tmp/rclone894978018: Waiting for checks to finish 2020/05/15 06:16:22 DEBUG : Local file system at /tmp/rclone894978018: Waiting for transfers to finish 2020/05/15 06:16:22 DEBUG : Waiting for deletions to finish 2020/05/15 06:16:22 INFO : enormous: Deleted 2020/05/15 06:16:22 INFO : potato2: Deleted 2020/05/15 06:16:22 INFO : There was nothing to transfer --- PASS: TestSyncWithExcludeAndDeleteExcluded (6.45s) run.go:176: Remote "B2 bucket rclone-test-saruxoz2notuway2wititib9", Local "Local file system at /tmp/rclone894978018", Modify Window "1ms" === RUN TestSyncWithUpdateOlder 2020/05/15 06:16:25 DEBUG : one: Destination is newer than source, skipping 2020/05/15 06:16:25 DEBUG : four: Sizes differ (src 4 vs dst 8) 2020/05/15 06:16:25 DEBUG : four: Destination mod time is within 1s of source but files differ, transferring 2020/05/15 06:16:25 DEBUG : three: Sizes identical 2020/05/15 06:16:25 DEBUG : three: Destination mod time is within 1s of source and files identical, skipping 2020/05/15 06:16:25 DEBUG : B2 bucket rclone-test-saruxoz2notuway2wititib9: Waiting for checks to finish 2020/05/15 06:16:25 DEBUG : two: SHA-1 = ad782ecdac770fc6eb9a62e44f90873fb97fb26b (Local file system at /tmp/rclone894978018) 2020/05/15 06:16:25 DEBUG : two: SHA-1 = b10e0da85e90399abfec36c7376b20aa4596461b (B2 bucket rclone-test-saruxoz2notuway2wititib9) 2020/05/15 06:16:25 DEBUG : two: SHA-1 differ 2020/05/15 06:16:25 DEBUG : B2 bucket rclone-test-saruxoz2notuway2wititib9: Waiting for transfers to finish 2020/05/15 06:16:25 DEBUG : five: SHA-1 = 4db2c1df4610cd6c0da6b9197b066bfb4e9b9d00 OK 2020/05/15 06:16:25 INFO : five: Copied (new) 2020/05/15 06:16:29 DEBUG : two: SHA-1 = ad782ecdac770fc6eb9a62e44f90873fb97fb26b OK 2020/05/15 06:16:29 INFO : two: Copied (replaced existing) 2020/05/15 06:16:40 DEBUG : four: SHA-1 = 9f8f7eec5dea5ac43738721939c120318cbff1df OK 2020/05/15 06:16:40 INFO : four: Copied (replaced existing) 2020/05/15 06:16:40 DEBUG : Waiting for deletions to finish 2020/05/15 06:16:41 DEBUG : one: Destination is newer than source, skipping 2020/05/15 06:16:41 DEBUG : B2 bucket rclone-test-saruxoz2notuway2wititib9: Waiting for checks to finish 2020/05/15 06:16:41 DEBUG : five: SHA-1 = 4db2c1df4610cd6c0da6b9197b066bfb4e9b9d00 OK 2020/05/15 06:16:41 DEBUG : five: Size and SHA-1 of src and dst objects identical 2020/05/15 06:16:41 DEBUG : five: Destination mod time is within 1s of source and files identical, skipping 2020/05/15 06:16:41 DEBUG : three: SHA-1 = b802f384302cb24fbab0a44997e820bf2e8507bb (Local file system at /tmp/rclone894978018) 2020/05/15 06:16:41 DEBUG : four: SHA-1 = 9f8f7eec5dea5ac43738721939c120318cbff1df OK 2020/05/15 06:16:41 DEBUG : four: Size and SHA-1 of src and dst objects identical 2020/05/15 06:16:41 DEBUG : four: Destination mod time is within 1s of source and files identical, skipping 2020/05/15 06:16:41 DEBUG : three: SHA-1 = 03731cad13f4cf7b59703c77529381cdec1632e5 (B2 bucket rclone-test-saruxoz2notuway2wititib9) 2020/05/15 06:16:41 DEBUG : two: SHA-1 = ad782ecdac770fc6eb9a62e44f90873fb97fb26b OK 2020/05/15 06:16:41 DEBUG : three: SHA-1 differ 2020/05/15 06:16:41 DEBUG : two: Size and SHA-1 of src and dst objects identical 2020/05/15 06:16:41 DEBUG : two: Destination mod time is within 1s of source and files identical, skipping 2020/05/15 06:16:41 DEBUG : three: Destination mod time is within 1s of source but files differ, transferring 2020/05/15 06:16:41 DEBUG : B2 bucket rclone-test-saruxoz2notuway2wititib9: Waiting for transfers to finish 2020/05/15 06:16:42 DEBUG : three: SHA-1 = b802f384302cb24fbab0a44997e820bf2e8507bb OK 2020/05/15 06:16:42 INFO : three: Copied (replaced existing) 2020/05/15 06:16:42 DEBUG : Waiting for deletions to finish --- PASS: TestSyncWithUpdateOlder (22.06s) run.go:176: Remote "B2 bucket rclone-test-saruxoz2notuway2wititib9", Local "Local file system at /tmp/rclone894978018", Modify Window "1ms" === RUN TestSyncWithMaxDuration --- SKIP: TestSyncWithMaxDuration (0.00s) sync_test.go:997: Skipping test on non local remote === RUN TestSyncWithTrackRenames 2020/05/15 06:16:45 INFO : B2 bucket rclone-test-saruxoz2notuway2wititib9: Making map for --track-renames 2020/05/15 06:16:45 INFO : B2 bucket rclone-test-saruxoz2notuway2wititib9: Finished making map for --track-renames 2020/05/15 06:16:45 DEBUG : B2 bucket rclone-test-saruxoz2notuway2wititib9: Waiting for checks to finish 2020/05/15 06:16:45 DEBUG : B2 bucket rclone-test-saruxoz2notuway2wititib9: Waiting for renames to finish 2020/05/15 06:16:45 DEBUG : B2 bucket rclone-test-saruxoz2notuway2wititib9: Waiting for transfers to finish 2020/05/15 06:16:46 DEBUG : yam: SHA-1 = ad84b2fb6729688a5ee3225164a6d4d58465b33e OK 2020/05/15 06:16:46 INFO : yam: Copied (new) 2020/05/15 06:16:46 DEBUG : potato: SHA-1 = 1d1ac61cfffcfdd0a15cc9ae575fb06ca8c11fb5 OK 2020/05/15 06:16:46 INFO : potato: Copied (new) 2020/05/15 06:16:46 DEBUG : Waiting for deletions to finish 2020/05/15 06:16:46 DEBUG : potato: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2020/05/15 06:16:46 DEBUG : potato: Unchanged skipping 2020/05/15 06:16:46 INFO : B2 bucket rclone-test-saruxoz2notuway2wititib9: Making map for --track-renames 2020/05/15 06:16:46 INFO : B2 bucket rclone-test-saruxoz2notuway2wititib9: Finished making map for --track-renames 2020/05/15 06:16:46 DEBUG : B2 bucket rclone-test-saruxoz2notuway2wititib9: Waiting for checks to finish 2020/05/15 06:16:46 DEBUG : B2 bucket rclone-test-saruxoz2notuway2wititib9: Waiting for renames to finish 2020/05/15 06:16:47 DEBUG : yam: SHA-1 = ad84b2fb6729688a5ee3225164a6d4d58465b33e OK 2020/05/15 06:16:47 INFO : yam: Copied (server side copy) 2020/05/15 06:16:48 INFO : yam: Deleted 2020/05/15 06:16:48 INFO : yaml: Renamed from "yam" 2020/05/15 06:16:48 DEBUG : B2 bucket rclone-test-saruxoz2notuway2wititib9: Waiting for transfers to finish 2020/05/15 06:16:48 DEBUG : Waiting for deletions to finish --- PASS: TestSyncWithTrackRenames (4.44s) run.go:176: Remote "B2 bucket rclone-test-saruxoz2notuway2wititib9", Local "Local file system at /tmp/rclone894978018", Modify Window "1ms" sync_test.go:1051: Can track renames: true === RUN TestParseRenamesStrategyModtime --- PASS: TestParseRenamesStrategyModtime (0.00s) === RUN TestRenamesStrategyModtime --- PASS: TestRenamesStrategyModtime (0.00s) === RUN TestSyncWithTrackRenamesStrategyModtime 2020/05/15 06:16:49 INFO : B2 bucket rclone-test-saruxoz2notuway2wititib9: Making map for --track-renames 2020/05/15 06:16:49 INFO : B2 bucket rclone-test-saruxoz2notuway2wititib9: Finished making map for --track-renames 2020/05/15 06:16:49 DEBUG : B2 bucket rclone-test-saruxoz2notuway2wititib9: Waiting for checks to finish 2020/05/15 06:16:49 DEBUG : B2 bucket rclone-test-saruxoz2notuway2wititib9: Waiting for renames to finish 2020/05/15 06:16:49 DEBUG : B2 bucket rclone-test-saruxoz2notuway2wititib9: Waiting for transfers to finish 2020/05/15 06:16:50 DEBUG : yam: SHA-1 = ad84b2fb6729688a5ee3225164a6d4d58465b33e OK 2020/05/15 06:16:50 INFO : yam: Copied (new) 2020/05/15 06:16:51 DEBUG : potato: SHA-1 = 1d1ac61cfffcfdd0a15cc9ae575fb06ca8c11fb5 OK 2020/05/15 06:16:51 INFO : potato: Copied (new) 2020/05/15 06:16:51 DEBUG : Waiting for deletions to finish 2020/05/15 06:16:51 DEBUG : potato: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2020/05/15 06:16:51 INFO : B2 bucket rclone-test-saruxoz2notuway2wititib9: Making map for --track-renames 2020/05/15 06:16:51 DEBUG : potato: Unchanged skipping 2020/05/15 06:16:51 INFO : B2 bucket rclone-test-saruxoz2notuway2wititib9: Finished making map for --track-renames 2020/05/15 06:16:51 DEBUG : B2 bucket rclone-test-saruxoz2notuway2wititib9: Waiting for checks to finish 2020/05/15 06:16:51 DEBUG : B2 bucket rclone-test-saruxoz2notuway2wititib9: Waiting for renames to finish 2020/05/15 06:16:52 DEBUG : yam: SHA-1 = ad84b2fb6729688a5ee3225164a6d4d58465b33e OK 2020/05/15 06:16:52 INFO : yam: Copied (server side copy) 2020/05/15 06:16:52 INFO : yam: Deleted 2020/05/15 06:16:52 INFO : yaml: Renamed from "yam" 2020/05/15 06:16:52 DEBUG : B2 bucket rclone-test-saruxoz2notuway2wititib9: Waiting for transfers to finish 2020/05/15 06:16:52 DEBUG : Waiting for deletions to finish --- PASS: TestSyncWithTrackRenamesStrategyModtime (4.57s) run.go:176: Remote "B2 bucket rclone-test-saruxoz2notuway2wititib9", Local "Local file system at /tmp/rclone894978018", Modify Window "1ms" sync_test.go:1122: Can track renames: true === RUN TestMoveWithDeleteEmptySrcDirs 2020/05/15 06:16:54 DEBUG : B2 bucket rclone-test-saruxoz2notuway2wititib9: Waiting for checks to finish 2020/05/15 06:16:54 DEBUG : B2 bucket rclone-test-saruxoz2notuway2wititib9: Waiting for transfers to finish 2020/05/15 06:16:54 DEBUG : nested/sub dir/file: SHA-1 = b4b3e0a278988bc15f2913af3f4153ccef74e465 OK 2020/05/15 06:16:54 INFO : nested/sub dir/file: Copied (new) 2020/05/15 06:16:54 INFO : nested/sub dir/file: Deleted 2020/05/15 06:16:55 DEBUG : sub dir/hello world: SHA-1 = 2aae6c35c94fcfb415dbe95f408b9ce91ee846ed OK 2020/05/15 06:16:55 INFO : sub dir/hello world: Copied (new) 2020/05/15 06:16:55 INFO : sub dir/hello world: Deleted 2020/05/15 06:16:55 DEBUG : sub dir: Removing directory 2020/05/15 06:16:55 DEBUG : nested/sub dir: Removing directory 2020/05/15 06:16:55 DEBUG : nested: Removing directory 2020/05/15 06:16:55 DEBUG : Local file system at /tmp/rclone894978018: deleted 3 directories --- PASS: TestMoveWithDeleteEmptySrcDirs (2.83s) run.go:176: Remote "B2 bucket rclone-test-saruxoz2notuway2wititib9", Local "Local file system at /tmp/rclone894978018", Modify Window "1ms" === RUN TestMoveWithoutDeleteEmptySrcDirs 2020/05/15 06:16:57 DEBUG : B2 bucket rclone-test-saruxoz2notuway2wititib9: Waiting for checks to finish 2020/05/15 06:16:57 DEBUG : B2 bucket rclone-test-saruxoz2notuway2wititib9: Waiting for transfers to finish 2020/05/15 06:16:57 DEBUG : sub dir/hello world: SHA-1 = 2aae6c35c94fcfb415dbe95f408b9ce91ee846ed OK 2020/05/15 06:16:57 INFO : sub dir/hello world: Copied (new) 2020/05/15 06:16:57 INFO : sub dir/hello world: Deleted 2020/05/15 06:17:01 DEBUG : nested/sub dir/file: SHA-1 = b4b3e0a278988bc15f2913af3f4153ccef74e465 OK 2020/05/15 06:17:01 INFO : nested/sub dir/file: Copied (new) 2020/05/15 06:17:01 INFO : nested/sub dir/file: Deleted --- PASS: TestMoveWithoutDeleteEmptySrcDirs (5.15s) run.go:176: Remote "B2 bucket rclone-test-saruxoz2notuway2wititib9", Local "Local file system at /tmp/rclone894978018", Modify Window "1ms" === RUN TestServerSideMove 2020/05/15 06:17:45 DEBUG : empty space: Size and modification time the same (differ by 0s, within tolerance 1ms) 2020/05/15 06:17:45 DEBUG : empty space: Unchanged skipping 2020/05/15 06:17:45 DEBUG : potato3: Sizes differ (src 68 vs dst 60) 2020/05/15 06:17:45 DEBUG : B2 bucket rclone-test-zuxaxiy3wuromiy7hezuges2: Waiting for checks to finish 2020/05/15 06:17:45 DEBUG : potato2: SHA-1 = 9dc7f7d3279715991a22853f5981df582b7f9f6d OK 2020/05/15 06:17:45 INFO : potato2: Copied (server side copy) 2020/05/15 06:17:46 INFO : potato2: Deleted 2020/05/15 06:17:46 DEBUG : potato3: SHA-1 = 568f8850f3c1a384731dbe40c6d72e1dcae342a0 OK 2020/05/15 06:17:46 INFO : potato3: Copied (server side copy) 2020/05/15 06:17:46 INFO : potato3: Deleted 2020/05/15 06:18:15 INFO : empty space: Deleted 2020/05/15 06:18:15 DEBUG : B2 bucket rclone-test-zuxaxiy3wuromiy7hezuges2: Waiting for transfers to finish 2020/05/15 06:18:17 DEBUG : B2 bucket rclone-test-saquvew1kedowuq6filewiq8: Waiting for checks to finish 2020/05/15 06:18:17 DEBUG : B2 bucket rclone-test-saquvew1kedowuq6filewiq8: Waiting for transfers to finish 2020/05/15 06:18:18 DEBUG : potato2: SHA-1 = 9dc7f7d3279715991a22853f5981df582b7f9f6d OK 2020/05/15 06:18:18 INFO : potato2: Copied (server side copy) 2020/05/15 06:18:18 DEBUG : empty space: SHA-1 = 3bc15c8aae3e4124dd409035f32ea2fd6835efc9 OK 2020/05/15 06:18:18 INFO : empty space: Copied (server side copy) 2020/05/15 06:18:19 INFO : empty space: Deleted 2020/05/15 06:18:19 DEBUG : potato3: SHA-1 = 568f8850f3c1a384731dbe40c6d72e1dcae342a0 OK 2020/05/15 06:18:19 INFO : potato3: Copied (server side copy) 2020/05/15 06:18:19 INFO : potato3: Deleted 2020/05/15 06:18:21 INFO : potato2: Deleted 2020/05/15 06:18:22 DEBUG : B2 bucket rclone-test-saquvew1kedowuq6filewiq8: Purge remote 2020/05/15 06:18:22 DEBUG : empty space: Deleting (id "4_zbf12cd03f0bd1b6b7f280e1b_f109f30dad2878ef0_d20200515_m061817_c001_v0001136_t0004") 2020/05/15 06:18:22 DEBUG : potato2: Deleting (id "4_zbf12cd03f0bd1b6b7f280e1b_f108addb697cbad08_d20200515_m061817_c001_v0001136_t0037") 2020/05/15 06:18:22 DEBUG : potato3: Deleting (id "4_zbf12cd03f0bd1b6b7f280e1b_f1015bff5ae3a3c9d_d20200515_m061818_c001_v0001120_t0059") 2020/05/15 06:18:22 DEBUG : B2 bucket rclone-test-zuxaxiy3wuromiy7hezuges2: Purge remote 2020/05/15 06:18:22 DEBUG : empty space: Deleting (id "4_zcfa23da3f0bd1b6b7f280e1b_f114768723e086e17_d20200515_m061818_c001_v0001137_t0010") 2020/05/15 06:18:22 DEBUG : empty space: Deleting (id "4_zcfa23da3f0bd1b6b7f280e1b_f104f9a9ebc4221cf_d20200515_m061743_c001_v0001134_t0018") 2020/05/15 06:18:22 DEBUG : potato2: Deleting (id "4_zcfa23da3f0bd1b6b7f280e1b_f100a65582cf61094_d20200515_m061818_c001_v0001037_t0047") 2020/05/15 06:18:22 DEBUG : potato2: Deleting (id "4_zcfa23da3f0bd1b6b7f280e1b_f101e241bc4f067b6_d20200515_m061745_c001_v0001017_t0038") 2020/05/15 06:18:22 DEBUG : potato3: Deleting (id "4_zcfa23da3f0bd1b6b7f280e1b_f119844f30766b731_d20200515_m061819_c001_v0001091_t0016") 2020/05/15 06:18:22 DEBUG : potato3: Deleting (id "4_zcfa23da3f0bd1b6b7f280e1b_f1061bb9b9b45042e_d20200515_m061745_c001_v0001113_t0053") 2020/05/15 06:18:22 DEBUG : potato3: Deleting (id "4_zcfa23da3f0bd1b6b7f280e1b_f104f9a9ebc4221d3_d20200515_m061744_c001_v0001134_t0018") --- PASS: TestServerSideMove (81.60s) run.go:176: Remote "B2 bucket rclone-test-saruxoz2notuway2wititib9", Local "Local file system at /tmp/rclone894978018", Modify Window "1ms" sync_test.go:1174: Server side move (if possible) B2 bucket rclone-test-saruxoz2notuway2wititib9 -> B2 bucket rclone-test-zuxaxiy3wuromiy7hezuges2 === RUN TestServerSideMoveWithFilter 2020/05/15 06:18:30 DEBUG : empty space: Excluded from sync (and deletion) 2020/05/15 06:18:30 DEBUG : empty space: Excluded from sync (and deletion) 2020/05/15 06:18:30 DEBUG : B2 bucket rclone-test-cisayoj2welutug5daxoyoj8: Waiting for checks to finish 2020/05/15 06:18:30 DEBUG : potato3: Sizes differ (src 68 vs dst 60) 2020/05/15 06:18:30 DEBUG : B2 bucket rclone-test-cisayoj2welutug5daxoyoj8: Waiting for transfers to finish 2020/05/15 06:18:31 DEBUG : potato3: SHA-1 = 568f8850f3c1a384731dbe40c6d72e1dcae342a0 OK 2020/05/15 06:18:31 INFO : potato3: Copied (server side copy) 2020/05/15 06:18:31 INFO : potato3: Deleted 2020/05/15 06:18:32 DEBUG : potato2: SHA-1 = 9dc7f7d3279715991a22853f5981df582b7f9f6d OK 2020/05/15 06:18:32 INFO : potato2: Copied (server side copy) 2020/05/15 06:18:33 INFO : potato2: Deleted 2020/05/15 06:18:34 DEBUG : empty space: Excluded from sync (and deletion) 2020/05/15 06:18:34 DEBUG : B2 bucket rclone-test-qeqesof4befibid0qepapeg7: Waiting for checks to finish 2020/05/15 06:18:34 DEBUG : B2 bucket rclone-test-qeqesof4befibid0qepapeg7: Waiting for transfers to finish 2020/05/15 06:18:35 DEBUG : potato2: SHA-1 = 9dc7f7d3279715991a22853f5981df582b7f9f6d OK 2020/05/15 06:18:35 INFO : potato2: Copied (server side copy) 2020/05/15 06:18:36 INFO : potato2: Deleted 2020/05/15 06:18:36 DEBUG : potato3: SHA-1 = 568f8850f3c1a384731dbe40c6d72e1dcae342a0 OK 2020/05/15 06:18:36 INFO : potato3: Copied (server side copy) 2020/05/15 06:18:37 INFO : potato3: Deleted 2020/05/15 06:18:37 DEBUG : B2 bucket rclone-test-qeqesof4befibid0qepapeg7: Purge remote 2020/05/15 06:18:37 DEBUG : potato2: Deleting (id "4_zbf020d43f0cd1b6b7f280e1b_f103d0314a0d01557_d20200515_m061834_c001_v0001137_t0008") 2020/05/15 06:18:37 DEBUG : potato3: Deleting (id "4_zbf020d43f0cd1b6b7f280e1b_f10408141a8df5e34_d20200515_m061835_c001_v0001137_t0009") 2020/05/15 06:18:38 DEBUG : B2 bucket rclone-test-cisayoj2welutug5daxoyoj8: Purge remote 2020/05/15 06:18:38 DEBUG : empty space: Deleting (id "4_z1f82eda3f0bd1b6b7f280e1b_f114768723e086f2c_d20200515_m061828_c001_v0001137_t0038") 2020/05/15 06:18:38 DEBUG : potato2: Deleting (id "4_z1f82eda3f0bd1b6b7f280e1b_f1190ad2f91911fc1_d20200515_m061835_c001_v0001113_t0054") 2020/05/15 06:18:38 DEBUG : potato2: Deleting (id "4_z1f82eda3f0bd1b6b7f280e1b_f110b02bc7b62b0b9_d20200515_m061830_c001_v0001113_t0049") 2020/05/15 06:18:38 DEBUG : potato3: Deleting (id "4_z1f82eda3f0bd1b6b7f280e1b_f1006c2c426142c3f_d20200515_m061836_c001_v0001137_t0018") 2020/05/15 06:18:38 DEBUG : potato3: Deleting (id "4_z1f82eda3f0bd1b6b7f280e1b_f107d445bea6a1334_d20200515_m061830_c001_v0001137_t0001") 2020/05/15 06:18:38 DEBUG : potato3: Deleting (id "4_z1f82eda3f0bd1b6b7f280e1b_f114768723e086f39_d20200515_m061829_c001_v0001137_t0038") --- PASS: TestServerSideMoveWithFilter (15.82s) run.go:176: Remote "B2 bucket rclone-test-saruxoz2notuway2wititib9", Local "Local file system at /tmp/rclone894978018", Modify Window "1ms" sync_test.go:1174: Server side move (if possible) B2 bucket rclone-test-saruxoz2notuway2wititib9 -> B2 bucket rclone-test-cisayoj2welutug5daxoyoj8 === RUN TestServerSideMoveDeleteEmptySourceDirs 2020/05/15 06:19:23 DEBUG : tomatoDir: Making directory 2020/05/15 06:19:27 DEBUG : empty space: Size and modification time the same (differ by 0s, within tolerance 1ms) 2020/05/15 06:19:27 DEBUG : empty space: Unchanged skipping 2020/05/15 06:19:27 DEBUG : B2 bucket rclone-test-mabotiz8pegukap5janusak3: Waiting for checks to finish 2020/05/15 06:19:27 DEBUG : potato3: Sizes differ (src 68 vs dst 60) 2020/05/15 06:19:28 DEBUG : potato2: SHA-1 = 9dc7f7d3279715991a22853f5981df582b7f9f6d OK 2020/05/15 06:19:28 INFO : potato2: Copied (server side copy) 2020/05/15 06:19:28 INFO : empty space: Deleted 2020/05/15 06:19:28 DEBUG : B2 bucket rclone-test-mabotiz8pegukap5janusak3: Waiting for transfers to finish 2020/05/15 06:19:29 DEBUG : potato3: SHA-1 = 568f8850f3c1a384731dbe40c6d72e1dcae342a0 OK 2020/05/15 06:19:29 INFO : potato3: Copied (server side copy) 2020/05/15 06:19:29 INFO : potato2: Deleted 2020/05/15 06:19:29 INFO : potato3: Deleted 2020/05/15 06:19:30 DEBUG : tomatoDir: Making directory 2020/05/15 06:19:30 DEBUG : B2 bucket rclone-test-dicorik8tafuwiy2vopilan5: Waiting for checks to finish 2020/05/15 06:19:30 DEBUG : B2 bucket rclone-test-dicorik8tafuwiy2vopilan5: Waiting for transfers to finish 2020/05/15 06:19:31 DEBUG : empty space: SHA-1 = 3bc15c8aae3e4124dd409035f32ea2fd6835efc9 OK 2020/05/15 06:19:31 INFO : empty space: Copied (server side copy) 2020/05/15 06:19:31 DEBUG : potato2: SHA-1 = 9dc7f7d3279715991a22853f5981df582b7f9f6d OK 2020/05/15 06:19:31 INFO : potato2: Copied (server side copy) 2020/05/15 06:19:32 INFO : potato2: Deleted 2020/05/15 06:19:32 DEBUG : potato3: SHA-1 = 568f8850f3c1a384731dbe40c6d72e1dcae342a0 OK 2020/05/15 06:19:32 INFO : potato3: Copied (server side copy) 2020/05/15 06:19:32 INFO : empty space: Deleted 2020/05/15 06:19:33 INFO : potato3: Deleted 2020/05/15 06:19:33 DEBUG : B2 bucket rclone-test-dicorik8tafuwiy2vopilan5: Purge remote 2020/05/15 06:19:33 DEBUG : empty space: Deleting (id "4_z7ff2ed03f0cd1b6b7f280e1b_f1100d102b072a145_d20200515_m061931_c001_v0001130_t0054") 2020/05/15 06:19:33 DEBUG : potato2: Deleting (id "4_z7ff2ed03f0cd1b6b7f280e1b_f105ebcc7e97c6155_d20200515_m061931_c001_v0001137_t0045") 2020/05/15 06:19:33 DEBUG : potato3: Deleting (id "4_z7ff2ed03f0cd1b6b7f280e1b_f118ee8a7d7d58526_d20200515_m061931_c001_v0001136_t0056") 2020/05/15 06:19:34 DEBUG : B2 bucket rclone-test-mabotiz8pegukap5janusak3: Purge remote 2020/05/15 06:19:34 DEBUG : empty space: Deleting (id "4_z0ff2cd63f0cd1b6b7f280e1b_f105ebcc7e97c615a_d20200515_m061931_c001_v0001137_t0054") 2020/05/15 06:19:34 DEBUG : empty space: Deleting (id "4_z0ff2cd63f0cd1b6b7f280e1b_f1192345ec07ac7ae_d20200515_m061924_c001_v0001137_t0039") 2020/05/15 06:19:34 DEBUG : potato2: Deleting (id "4_z0ff2cd63f0cd1b6b7f280e1b_f1002796a8260e547_d20200515_m061932_c001_v0001134_t0013") 2020/05/15 06:19:34 DEBUG : potato2: Deleting (id "4_z0ff2cd63f0cd1b6b7f280e1b_f112782e232bd7d4a_d20200515_m061928_c001_v0001131_t0048") 2020/05/15 06:19:34 DEBUG : potato3: Deleting (id "4_z0ff2cd63f0cd1b6b7f280e1b_f1137e31506bf944e_d20200515_m061932_c001_v0001137_t0026") 2020/05/15 06:19:34 DEBUG : potato3: Deleting (id "4_z0ff2cd63f0cd1b6b7f280e1b_f11937c7da862974f_d20200515_m061928_c001_v0001134_t0046") 2020/05/15 06:19:34 DEBUG : potato3: Deleting (id "4_z0ff2cd63f0cd1b6b7f280e1b_f1192345ec07ac7d4_d20200515_m061927_c001_v0001137_t0039") --- PASS: TestServerSideMoveDeleteEmptySourceDirs (55.69s) run.go:176: Remote "B2 bucket rclone-test-saruxoz2notuway2wititib9", Local "Local file system at /tmp/rclone894978018", Modify Window "1ms" sync_test.go:1174: Server side move (if possible) B2 bucket rclone-test-saruxoz2notuway2wititib9 -> B2 bucket rclone-test-mabotiz8pegukap5janusak3 === RUN TestServerSideMoveOverlap --- PASS: TestServerSideMoveOverlap (43.36s) run.go:176: Remote "B2 bucket rclone-test-saruxoz2notuway2wititib9", Local "Local file system at /tmp/rclone894978018", Modify Window "1ms" === RUN TestSyncOverlap --- PASS: TestSyncOverlap (1.23s) run.go:176: Remote "B2 bucket rclone-test-saruxoz2notuway2wititib9", Local "Local file system at /tmp/rclone894978018", Modify Window "1ms" === RUN TestSyncCompareDest 2020/05/15 06:20:21 DEBUG : B2 bucket rclone-test-saruxoz2notuway2wititib9 path dst: Waiting for checks to finish 2020/05/15 06:20:21 DEBUG : B2 bucket rclone-test-saruxoz2notuway2wititib9 path dst: Waiting for transfers to finish 2020/05/15 06:20:22 DEBUG : one: SHA-1 = fe05bcdcdc4928012781a5f1a2a77cbb5398e106 OK 2020/05/15 06:20:22 INFO : one: Copied (new) 2020/05/15 06:20:22 DEBUG : Waiting for deletions to finish 2020/05/15 06:20:22 DEBUG : B2 bucket rclone-test-saruxoz2notuway2wititib9 path dst: Waiting for checks to finish 2020/05/15 06:20:23 DEBUG : one: Sizes differ (src 5 vs dst 3) 2020/05/15 06:20:23 DEBUG : B2 bucket rclone-test-saruxoz2notuway2wititib9 path dst: Waiting for transfers to finish 2020/05/15 06:20:23 DEBUG : one: SHA-1 = 7f376fd65843a1267de8f986d40e164e5a321c13 OK 2020/05/15 06:20:23 INFO : one: Copied (replaced existing) 2020/05/15 06:20:23 DEBUG : Waiting for deletions to finish 2020/05/15 06:20:26 DEBUG : B2 bucket rclone-test-saruxoz2notuway2wititib9 path dst: Waiting for checks to finish 2020/05/15 06:20:26 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2020/05/15 06:20:26 DEBUG : one: Destination found in --compare-dest, skipping 2020/05/15 06:20:26 DEBUG : B2 bucket rclone-test-saruxoz2notuway2wititib9 path dst: Waiting for transfers to finish 2020/05/15 06:20:26 DEBUG : Waiting for deletions to finish 2020/05/15 06:20:26 INFO : There was nothing to transfer 2020/05/15 06:20:27 DEBUG : two: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2020/05/15 06:20:27 DEBUG : two: Destination found in --compare-dest, skipping 2020/05/15 06:20:27 DEBUG : B2 bucket rclone-test-saruxoz2notuway2wititib9 path dst: Waiting for checks to finish 2020/05/15 06:20:27 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2020/05/15 06:20:27 DEBUG : one: Destination found in --compare-dest, skipping 2020/05/15 06:20:27 DEBUG : B2 bucket rclone-test-saruxoz2notuway2wititib9 path dst: Waiting for transfers to finish 2020/05/15 06:20:27 DEBUG : Waiting for deletions to finish 2020/05/15 06:20:27 INFO : There was nothing to transfer 2020/05/15 06:20:28 DEBUG : two: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2020/05/15 06:20:28 DEBUG : two: Destination found in --compare-dest, skipping 2020/05/15 06:20:28 DEBUG : B2 bucket rclone-test-saruxoz2notuway2wititib9 path dst: Waiting for checks to finish 2020/05/15 06:20:28 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2020/05/15 06:20:28 DEBUG : one: Destination found in --compare-dest, skipping 2020/05/15 06:20:28 DEBUG : B2 bucket rclone-test-saruxoz2notuway2wititib9 path dst: Waiting for transfers to finish 2020/05/15 06:20:28 DEBUG : Waiting for deletions to finish 2020/05/15 06:20:28 INFO : There was nothing to transfer 2020/05/15 06:20:28 DEBUG : two: Sizes differ (src 5 vs dst 3) 2020/05/15 06:20:28 DEBUG : B2 bucket rclone-test-saruxoz2notuway2wititib9 path dst: Waiting for checks to finish 2020/05/15 06:20:29 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2020/05/15 06:20:29 DEBUG : one: Destination found in --compare-dest, skipping 2020/05/15 06:20:29 DEBUG : B2 bucket rclone-test-saruxoz2notuway2wititib9 path dst: Waiting for transfers to finish 2020/05/15 06:20:30 DEBUG : two: SHA-1 = a4be8877ad88f3109a6411985a1f359e10e2d930 OK 2020/05/15 06:20:30 INFO : two: Copied (new) 2020/05/15 06:20:30 DEBUG : Waiting for deletions to finish --- PASS: TestSyncCompareDest (12.90s) run.go:176: Remote "B2 bucket rclone-test-saruxoz2notuway2wititib9", Local "Local file system at /tmp/rclone894978018", Modify Window "1ms" === RUN TestSyncCopyDest 2020/05/15 06:20:34 DEBUG : B2 bucket rclone-test-saruxoz2notuway2wititib9 path dst: Waiting for checks to finish 2020/05/15 06:20:34 DEBUG : B2 bucket rclone-test-saruxoz2notuway2wititib9 path dst: Waiting for transfers to finish 2020/05/15 06:20:35 DEBUG : one: SHA-1 = fe05bcdcdc4928012781a5f1a2a77cbb5398e106 OK 2020/05/15 06:20:35 INFO : one: Copied (new) 2020/05/15 06:20:35 DEBUG : Waiting for deletions to finish 2020/05/15 06:20:35 DEBUG : B2 bucket rclone-test-saruxoz2notuway2wititib9 path dst: Waiting for checks to finish 2020/05/15 06:20:35 DEBUG : one: Sizes differ (src 5 vs dst 3) 2020/05/15 06:20:35 DEBUG : B2 bucket rclone-test-saruxoz2notuway2wititib9 path dst: Waiting for transfers to finish 2020/05/15 06:20:36 DEBUG : one: SHA-1 = 7f376fd65843a1267de8f986d40e164e5a321c13 OK 2020/05/15 06:20:36 INFO : one: Copied (replaced existing) 2020/05/15 06:20:36 DEBUG : Waiting for deletions to finish 2020/05/15 06:20:40 DEBUG : B2 bucket rclone-test-saruxoz2notuway2wititib9 path dst: Waiting for checks to finish 2020/05/15 06:20:40 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2020/05/15 06:20:40 DEBUG : one: Sizes differ (src 5 vs dst 3) 2020/05/15 06:20:41 DEBUG : one: SHA-1 = fe05bcdcdc4928012781a5f1a2a77cbb5398e106 OK 2020/05/15 06:20:41 INFO : one: Copied (server side copy) 2020/05/15 06:21:02 INFO : one: Deleted 2020/05/15 06:21:02 DEBUG : one: SHA-1 = 7f376fd65843a1267de8f986d40e164e5a321c13 OK 2020/05/15 06:21:02 INFO : one: Copied (server side copy) 2020/05/15 06:21:02 DEBUG : one: Destination found in --copy-dest, using server side copy 2020/05/15 06:21:02 DEBUG : B2 bucket rclone-test-saruxoz2notuway2wititib9 path dst: Waiting for transfers to finish 2020/05/15 06:21:02 DEBUG : Waiting for deletions to finish 2020/05/15 06:21:17 DEBUG : two: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2020/05/15 06:21:18 DEBUG : two: SHA-1 = ad782ecdac770fc6eb9a62e44f90873fb97fb26b OK 2020/05/15 06:21:18 INFO : two: Copied (server side copy) 2020/05/15 06:21:18 DEBUG : two: Destination found in --copy-dest, using server side copy 2020/05/15 06:21:18 DEBUG : B2 bucket rclone-test-saruxoz2notuway2wititib9 path dst: Waiting for checks to finish 2020/05/15 06:21:18 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2020/05/15 06:21:18 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2020/05/15 06:21:18 DEBUG : one: Unchanged skipping 2020/05/15 06:21:18 DEBUG : B2 bucket rclone-test-saruxoz2notuway2wititib9 path dst: Waiting for transfers to finish 2020/05/15 06:21:18 DEBUG : Waiting for deletions to finish 2020/05/15 06:21:18 DEBUG : B2 bucket rclone-test-saruxoz2notuway2wititib9 path dst: Waiting for checks to finish 2020/05/15 06:21:18 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2020/05/15 06:21:18 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2020/05/15 06:21:18 DEBUG : one: Unchanged skipping 2020/05/15 06:21:18 DEBUG : two: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2020/05/15 06:21:18 DEBUG : two: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2020/05/15 06:21:18 DEBUG : two: Unchanged skipping 2020/05/15 06:21:18 DEBUG : B2 bucket rclone-test-saruxoz2notuway2wititib9 path dst: Waiting for transfers to finish 2020/05/15 06:21:18 DEBUG : Waiting for deletions to finish 2020/05/15 06:21:18 INFO : There was nothing to transfer 2020/05/15 06:21:20 DEBUG : three: Sizes differ (src 7 vs dst 5) 2020/05/15 06:21:20 DEBUG : three: Destination not found in --copy-dest 2020/05/15 06:21:20 DEBUG : B2 bucket rclone-test-saruxoz2notuway2wititib9 path dst: Waiting for checks to finish 2020/05/15 06:21:20 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2020/05/15 06:21:20 DEBUG : one: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2020/05/15 06:21:20 DEBUG : one: Unchanged skipping 2020/05/15 06:21:20 DEBUG : two: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2020/05/15 06:21:20 DEBUG : two: Size and modification time the same (differ by -456.789µs, within tolerance 1ms) 2020/05/15 06:21:20 DEBUG : two: Unchanged skipping 2020/05/15 06:21:20 DEBUG : B2 bucket rclone-test-saruxoz2notuway2wititib9 path dst: Waiting for transfers to finish 2020/05/15 06:21:21 DEBUG : three: SHA-1 = 370e613335f3cf2f19b2a2d35a86402f55c659f8 OK 2020/05/15 06:21:21 INFO : three: Copied (new) 2020/05/15 06:21:21 DEBUG : Waiting for deletions to finish --- PASS: TestSyncCopyDest (54.88s) run.go:176: Remote "B2 bucket rclone-test-saruxoz2notuway2wititib9", Local "Local file system at /tmp/rclone894978018", Modify Window "1ms" === RUN TestSyncBackupDir 2020/05/15 06:21:32 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2020/05/15 06:21:32 DEBUG : two: Unchanged skipping 2020/05/15 06:21:32 DEBUG : one: Sizes differ (src 4 vs dst 3) 2020/05/15 06:21:32 DEBUG : B2 bucket rclone-test-saruxoz2notuway2wititib9 path dst: Waiting for checks to finish 2020/05/15 06:21:32 DEBUG : one: SHA-1 = fe05bcdcdc4928012781a5f1a2a77cbb5398e106 OK 2020/05/15 06:21:32 INFO : one: Copied (server side copy) 2020/05/15 06:21:33 INFO : one: Deleted 2020/05/15 06:21:33 DEBUG : B2 bucket rclone-test-saruxoz2notuway2wititib9 path dst: Waiting for transfers to finish 2020/05/15 06:21:45 DEBUG : one: SHA-1 = d63a9910ed57f038b76549c070df6196b2102f42 OK 2020/05/15 06:21:45 INFO : one: Copied (new) 2020/05/15 06:21:45 DEBUG : Waiting for deletions to finish 2020/05/15 06:21:46 DEBUG : three.txt: SHA-1 = b802f384302cb24fbab0a44997e820bf2e8507bb OK 2020/05/15 06:21:46 INFO : three.txt: Copied (server side copy) 2020/05/15 06:21:47 INFO : three.txt: Deleted 2020/05/15 06:21:47 INFO : three.txt: Moved into backup dir 2020/05/15 06:21:48 DEBUG : B2 bucket rclone-test-saruxoz2notuway2wititib9 path dst: Waiting for checks to finish 2020/05/15 06:21:48 DEBUG : one: Sizes differ (src 5 vs dst 4) 2020/05/15 06:21:48 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2020/05/15 06:21:48 DEBUG : two: Unchanged skipping 2020/05/15 06:21:49 DEBUG : one: SHA-1 = d63a9910ed57f038b76549c070df6196b2102f42 OK 2020/05/15 06:21:49 INFO : one: Copied (server side copy) 2020/05/15 06:21:50 INFO : one: Deleted 2020/05/15 06:21:50 DEBUG : B2 bucket rclone-test-saruxoz2notuway2wititib9 path dst: Waiting for transfers to finish 2020/05/15 06:21:50 DEBUG : one: SHA-1 = 88a8c2880f555638f990d1ec4c8359b25caa20c7 OK 2020/05/15 06:21:50 INFO : one: Copied (new) 2020/05/15 06:21:50 DEBUG : Waiting for deletions to finish 2020/05/15 06:21:51 DEBUG : three.txt: SHA-1 = 92e0258fe3c7456f15dff78d509f6e3c9166c254 OK 2020/05/15 06:21:51 INFO : three.txt: Copied (server side copy) 2020/05/15 06:21:51 INFO : three.txt: Deleted 2020/05/15 06:21:51 INFO : three.txt: Moved into backup dir --- PASS: TestSyncBackupDir (26.03s) run.go:176: Remote "B2 bucket rclone-test-saruxoz2notuway2wititib9", Local "Local file system at /tmp/rclone894978018", Modify Window "1ms" === RUN TestSyncBackupDirWithSuffix 2020/05/15 06:22:14 DEBUG : B2 bucket rclone-test-saruxoz2notuway2wititib9 path dst: Waiting for checks to finish 2020/05/15 06:22:14 DEBUG : one: Sizes differ (src 4 vs dst 3) 2020/05/15 06:22:14 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2020/05/15 06:22:14 DEBUG : two: Unchanged skipping 2020/05/15 06:22:15 DEBUG : one: SHA-1 = fe05bcdcdc4928012781a5f1a2a77cbb5398e106 OK 2020/05/15 06:22:15 INFO : one: Copied (server side copy) 2020/05/15 06:22:15 INFO : one: Deleted 2020/05/15 06:22:15 DEBUG : B2 bucket rclone-test-saruxoz2notuway2wititib9 path dst: Waiting for transfers to finish 2020/05/15 06:22:20 DEBUG : one: SHA-1 = d63a9910ed57f038b76549c070df6196b2102f42 OK 2020/05/15 06:22:20 INFO : one: Copied (new) 2020/05/15 06:22:20 DEBUG : Waiting for deletions to finish 2020/05/15 06:22:21 DEBUG : pacer: low level retry 1/10 (error Post https://api001.backblazeb2.com/b2api/v1/b2_list_file_names: EOF) 2020/05/15 06:22:21 DEBUG : pacer: Rate limited, increasing sleep to 20ms 2020/05/15 06:22:21 DEBUG : pacer: Reducing sleep to 10ms 2020/05/15 06:22:22 DEBUG : three.txt: SHA-1 = b802f384302cb24fbab0a44997e820bf2e8507bb OK 2020/05/15 06:22:22 INFO : three.txt: Copied (server side copy) 2020/05/15 06:22:22 INFO : three.txt: Deleted 2020/05/15 06:22:22 INFO : three.txt: Moved into backup dir 2020/05/15 06:22:24 DEBUG : one: Sizes differ (src 5 vs dst 4) 2020/05/15 06:22:24 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2020/05/15 06:22:24 DEBUG : two: Unchanged skipping 2020/05/15 06:22:24 DEBUG : B2 bucket rclone-test-saruxoz2notuway2wititib9 path dst: Waiting for checks to finish 2020/05/15 06:22:24 DEBUG : one: SHA-1 = d63a9910ed57f038b76549c070df6196b2102f42 OK 2020/05/15 06:22:24 INFO : one: Copied (server side copy) 2020/05/15 06:22:24 INFO : one: Deleted 2020/05/15 06:22:24 DEBUG : B2 bucket rclone-test-saruxoz2notuway2wititib9 path dst: Waiting for transfers to finish 2020/05/15 06:22:29 DEBUG : one: SHA-1 = 88a8c2880f555638f990d1ec4c8359b25caa20c7 OK 2020/05/15 06:22:29 INFO : one: Copied (new) 2020/05/15 06:22:29 DEBUG : Waiting for deletions to finish 2020/05/15 06:22:29 DEBUG : three.txt: SHA-1 = 92e0258fe3c7456f15dff78d509f6e3c9166c254 OK 2020/05/15 06:22:29 INFO : three.txt: Copied (server side copy) 2020/05/15 06:22:30 INFO : three.txt: Deleted 2020/05/15 06:22:30 INFO : three.txt: Moved into backup dir --- PASS: TestSyncBackupDirWithSuffix (40.45s) run.go:176: Remote "B2 bucket rclone-test-saruxoz2notuway2wititib9", Local "Local file system at /tmp/rclone894978018", Modify Window "1ms" === RUN TestSyncBackupDirWithSuffixKeepExtension 2020/05/15 06:22:38 DEBUG : one: Sizes differ (src 4 vs dst 3) 2020/05/15 06:22:38 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2020/05/15 06:22:38 DEBUG : two: Unchanged skipping 2020/05/15 06:22:38 DEBUG : B2 bucket rclone-test-saruxoz2notuway2wititib9 path dst: Waiting for checks to finish 2020/05/15 06:22:39 DEBUG : one: SHA-1 = fe05bcdcdc4928012781a5f1a2a77cbb5398e106 OK 2020/05/15 06:22:39 INFO : one: Copied (server side copy) 2020/05/15 06:22:39 INFO : one: Deleted 2020/05/15 06:22:39 DEBUG : B2 bucket rclone-test-saruxoz2notuway2wititib9 path dst: Waiting for transfers to finish 2020/05/15 06:22:41 DEBUG : one: SHA-1 = d63a9910ed57f038b76549c070df6196b2102f42 OK 2020/05/15 06:22:41 INFO : one: Copied (new) 2020/05/15 06:22:41 DEBUG : Waiting for deletions to finish 2020/05/15 06:22:41 DEBUG : three.txt: SHA-1 = b802f384302cb24fbab0a44997e820bf2e8507bb OK 2020/05/15 06:22:41 INFO : three.txt: Copied (server side copy) 2020/05/15 06:22:42 INFO : three.txt: Deleted 2020/05/15 06:22:42 INFO : three.txt: Moved into backup dir 2020/05/15 06:22:43 DEBUG : B2 bucket rclone-test-saruxoz2notuway2wititib9 path dst: Waiting for checks to finish 2020/05/15 06:22:43 DEBUG : one: Sizes differ (src 5 vs dst 4) 2020/05/15 06:22:43 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2020/05/15 06:22:43 DEBUG : two: Unchanged skipping 2020/05/15 06:22:48 DEBUG : one: SHA-1 = d63a9910ed57f038b76549c070df6196b2102f42 OK 2020/05/15 06:22:48 INFO : one: Copied (server side copy) 2020/05/15 06:22:49 INFO : one: Deleted 2020/05/15 06:22:49 DEBUG : B2 bucket rclone-test-saruxoz2notuway2wititib9 path dst: Waiting for transfers to finish 2020/05/15 06:22:52 DEBUG : one: SHA-1 = 88a8c2880f555638f990d1ec4c8359b25caa20c7 OK 2020/05/15 06:22:52 INFO : one: Copied (new) 2020/05/15 06:22:52 DEBUG : Waiting for deletions to finish 2020/05/15 06:22:53 DEBUG : three.txt: SHA-1 = 92e0258fe3c7456f15dff78d509f6e3c9166c254 OK 2020/05/15 06:22:53 INFO : three.txt: Copied (server side copy) 2020/05/15 06:22:53 INFO : three.txt: Deleted 2020/05/15 06:22:53 INFO : three.txt: Moved into backup dir --- PASS: TestSyncBackupDirWithSuffixKeepExtension (21.43s) run.go:176: Remote "B2 bucket rclone-test-saruxoz2notuway2wititib9", Local "Local file system at /tmp/rclone894978018", Modify Window "1ms" === RUN TestSyncSuffix 2020/05/15 06:23:00 DEBUG : one: Sizes differ (src 4 vs dst 3) 2020/05/15 06:23:01 DEBUG : one: SHA-1 = fe05bcdcdc4928012781a5f1a2a77cbb5398e106 OK 2020/05/15 06:23:01 INFO : one: Copied (server side copy) 2020/05/15 06:23:01 INFO : one: Deleted 2020/05/15 06:23:02 DEBUG : one: SHA-1 = d63a9910ed57f038b76549c070df6196b2102f42 OK 2020/05/15 06:23:02 INFO : one: Copied (new) 2020/05/15 06:23:02 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2020/05/15 06:23:02 DEBUG : two: Unchanged skipping 2020/05/15 06:23:02 DEBUG : three.txt: Sizes differ (src 6 vs dst 5) 2020/05/15 06:23:03 DEBUG : three.txt: SHA-1 = b802f384302cb24fbab0a44997e820bf2e8507bb OK 2020/05/15 06:23:03 INFO : three.txt: Copied (server side copy) 2020/05/15 06:23:04 INFO : three.txt: Deleted 2020/05/15 06:23:06 DEBUG : three.txt: SHA-1 = 92e0258fe3c7456f15dff78d509f6e3c9166c254 OK 2020/05/15 06:23:06 INFO : three.txt: Copied (new) 2020/05/15 06:23:07 DEBUG : one: Sizes differ (src 5 vs dst 4) 2020/05/15 06:23:07 DEBUG : one: SHA-1 = d63a9910ed57f038b76549c070df6196b2102f42 OK 2020/05/15 06:23:07 INFO : one: Copied (server side copy) 2020/05/15 06:23:09 INFO : one: Deleted 2020/05/15 06:23:11 DEBUG : one: SHA-1 = 88a8c2880f555638f990d1ec4c8359b25caa20c7 OK 2020/05/15 06:23:11 INFO : one: Copied (new) 2020/05/15 06:23:11 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2020/05/15 06:23:11 DEBUG : two: Unchanged skipping 2020/05/15 06:23:11 DEBUG : three.txt: Sizes differ (src 19 vs dst 6) 2020/05/15 06:23:14 DEBUG : three.txt: SHA-1 = 92e0258fe3c7456f15dff78d509f6e3c9166c254 OK 2020/05/15 06:23:14 INFO : three.txt: Copied (server side copy) 2020/05/15 06:23:14 INFO : three.txt: Deleted 2020/05/15 06:23:15 DEBUG : three.txt: SHA-1 = 476e1707cbd7f0497a7dc4d44f0b07b8566ffc30 OK 2020/05/15 06:23:15 INFO : three.txt: Copied (new) --- FAIL: TestSyncSuffix (29.64s) run.go:176: Remote "B2 bucket rclone-test-saruxoz2notuway2wititib9", Local "Local file system at /tmp/rclone894978018", Modify Window "1ms" fstest.go:295: Sleeping for 1s for list eventual consistency: 1/3 fstest.go:295: Sleeping for 2s for list eventual consistency: 2/3 fstest.go:295: Sleeping for 4s for list eventual consistency: 3/3 fstest.go:302: Error Trace: fstest.go:302 fstest.go:335 fstest.go:347 sync_test.go:1703 sync_test.go:1705 Error: Should be true Test: TestSyncSuffix Messages: listing wrong, want dst/one (5), dst/one.bak (4), dst/three.txt (19), dst/three.txt.bak (6), dst/two (3) got dst/one (5), dst/one.bak (4), dst/three.txt.bak (6), dst/two (3) fstest.go:200: Not found "dst/three.txt" fstest.go:203: Error Trace: fstest.go:203 fstest.go:307 fstest.go:335 fstest.go:347 sync_test.go:1703 sync_test.go:1705 Error: Not equal: expected: 0 actual : 1 Test: TestSyncSuffix Messages: 1 objects not found === RUN TestSyncSuffixKeepExtension 2020/05/15 06:23:33 DEBUG : one: Sizes differ (src 4 vs dst 3) 2020/05/15 06:23:39 DEBUG : one: SHA-1 = fe05bcdcdc4928012781a5f1a2a77cbb5398e106 OK 2020/05/15 06:23:39 INFO : one: Copied (server side copy) 2020/05/15 06:23:40 INFO : one: Deleted 2020/05/15 06:23:41 DEBUG : one: SHA-1 = d63a9910ed57f038b76549c070df6196b2102f42 OK 2020/05/15 06:23:41 INFO : one: Copied (new) 2020/05/15 06:23:41 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2020/05/15 06:23:41 DEBUG : two: Unchanged skipping 2020/05/15 06:23:41 DEBUG : three.txt: Sizes differ (src 6 vs dst 5) 2020/05/15 06:23:42 DEBUG : three.txt: SHA-1 = b802f384302cb24fbab0a44997e820bf2e8507bb OK 2020/05/15 06:23:42 INFO : three.txt: Copied (server side copy) 2020/05/15 06:23:43 INFO : three.txt: Deleted 2020/05/15 06:23:44 DEBUG : three.txt: SHA-1 = 92e0258fe3c7456f15dff78d509f6e3c9166c254 OK 2020/05/15 06:23:44 INFO : three.txt: Copied (new) 2020/05/15 06:23:45 DEBUG : one: Sizes differ (src 5 vs dst 4) 2020/05/15 06:23:45 DEBUG : one: SHA-1 = d63a9910ed57f038b76549c070df6196b2102f42 OK 2020/05/15 06:23:45 INFO : one: Copied (server side copy) 2020/05/15 06:23:46 INFO : one: Deleted 2020/05/15 06:23:47 DEBUG : one: SHA-1 = 88a8c2880f555638f990d1ec4c8359b25caa20c7 OK 2020/05/15 06:23:47 INFO : one: Copied (new) 2020/05/15 06:23:47 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2020/05/15 06:23:47 DEBUG : two: Unchanged skipping 2020/05/15 06:23:47 DEBUG : three.txt: Sizes differ (src 19 vs dst 6) 2020/05/15 06:23:48 DEBUG : three.txt: SHA-1 = 92e0258fe3c7456f15dff78d509f6e3c9166c254 OK 2020/05/15 06:23:48 INFO : three.txt: Copied (server side copy) 2020/05/15 06:23:48 INFO : three.txt: Deleted 2020/05/15 06:23:48 DEBUG : three.txt: SHA-1 = 476e1707cbd7f0497a7dc4d44f0b07b8566ffc30 OK 2020/05/15 06:23:48 INFO : three.txt: Copied (new) --- PASS: TestSyncSuffixKeepExtension (34.45s) run.go:176: Remote "B2 bucket rclone-test-saruxoz2notuway2wititib9", Local "Local file system at /tmp/rclone894978018", Modify Window "1ms" === RUN TestSyncUTFNorm 2020/05/15 06:24:02 DEBUG : B2 bucket rclone-test-saruxoz2notuway2wititib9: Waiting for checks to finish 2020/05/15 06:24:02 DEBUG : Testêé: Sizes differ (src 14 vs dst 18) 2020/05/15 06:24:02 DEBUG : B2 bucket rclone-test-saruxoz2notuway2wititib9: Waiting for transfers to finish 2020/05/15 06:24:43 DEBUG : Testêé: SHA-1 = a54d88e06612d820bc3be72877c74f257b561b19 OK 2020/05/15 06:24:43 INFO : Testêé: Copied (replaced existing) 2020/05/15 06:24:43 DEBUG : Waiting for deletions to finish --- PASS: TestSyncUTFNorm (44.88s) run.go:176: Remote "B2 bucket rclone-test-saruxoz2notuway2wititib9", Local "Local file system at /tmp/rclone894978018", Modify Window "1ms" === RUN TestSyncImmutable 2020/05/15 06:24:45 DEBUG : B2 bucket rclone-test-saruxoz2notuway2wititib9: Waiting for checks to finish 2020/05/15 06:24:45 DEBUG : B2 bucket rclone-test-saruxoz2notuway2wititib9: Waiting for transfers to finish 2020/05/15 06:24:47 DEBUG : existing: SHA-1 = 3e2e95f5ad970eadfa7e17eaf73da97024aa5359 OK 2020/05/15 06:24:47 INFO : existing: Copied (new) 2020/05/15 06:24:47 DEBUG : Waiting for deletions to finish 2020/05/15 06:24:47 DEBUG : B2 bucket rclone-test-saruxoz2notuway2wititib9: Waiting for checks to finish 2020/05/15 06:24:47 DEBUG : existing: Sizes differ (src 8 vs dst 6) 2020/05/15 06:24:47 ERROR : existing: Source and destination exist but do not match: immutable file modified 2020/05/15 06:24:47 DEBUG : B2 bucket rclone-test-saruxoz2notuway2wititib9: Waiting for transfers to finish 2020/05/15 06:24:47 ERROR : B2 bucket rclone-test-saruxoz2notuway2wititib9: not deleting files as there were IO errors 2020/05/15 06:24:47 ERROR : B2 bucket rclone-test-saruxoz2notuway2wititib9: not deleting directories as there were IO errors 2020/05/15 06:24:47 INFO : There was nothing to transfer --- PASS: TestSyncImmutable (4.02s) run.go:176: Remote "B2 bucket rclone-test-saruxoz2notuway2wititib9", Local "Local file system at /tmp/rclone894978018", Modify Window "1ms" === RUN TestSyncIgnoreCase 2020/05/15 06:24:57 DEBUG : B2 bucket rclone-test-saruxoz2notuway2wititib9: Waiting for checks to finish 2020/05/15 06:24:57 DEBUG : existing: Size and modification time the same (differ by -999.999µs, within tolerance 1ms) 2020/05/15 06:24:57 DEBUG : existing: Unchanged skipping 2020/05/15 06:24:57 DEBUG : B2 bucket rclone-test-saruxoz2notuway2wititib9: Waiting for transfers to finish 2020/05/15 06:24:57 DEBUG : Waiting for deletions to finish 2020/05/15 06:24:57 INFO : There was nothing to transfer --- PASS: TestSyncIgnoreCase (9.86s) run.go:176: Remote "B2 bucket rclone-test-saruxoz2notuway2wititib9", Local "Local file system at /tmp/rclone894978018", Modify Window "1ms" === RUN TestAbort --- SKIP: TestAbort (0.29s) run.go:176: Remote "B2 bucket rclone-test-saruxoz2notuway2wititib9", Local "Local file system at /tmp/rclone894978018", Modify Window "1ms" sync_test.go:1807: This test only runs on local FAIL 2020/05/15 06:24:58 DEBUG : B2 bucket rclone-test-saruxoz2notuway2wititib9: Purge remote 2020/05/15 06:24:59 DEBUG : BackupDir/one: Deleting (id "4_z9fc25d43f07d1b6b7f280e1b_f101a5b5fadeccf56_d20200515_m062121_c001_v0001137_t0005") 2020/05/15 06:24:59 DEBUG : BackupDir/one: Deleting (id "4_z9fc25d43f07d1b6b7f280e1b_f103d0314a0d020a9_d20200515_m062040_c001_v0001137_t0032") 2020/05/15 06:24:59 DEBUG : CompareDest/one: Deleting (id "4_z9fc25d43f07d1b6b7f280e1b_f119320b248bc2593_d20200515_m062030_c001_v0001136_t0034") 2020/05/15 06:24:59 DEBUG : CompareDest/one: Deleting (id "4_z9fc25d43f07d1b6b7f280e1b_f115f4d52466066fb_d20200515_m062024_c001_v0001113_t0040") 2020/05/15 06:24:59 DEBUG : CompareDest/two: Deleting (id "4_z9fc25d43f07d1b6b7f280e1b_f116a782f7420006e_d20200515_m062031_c001_v0001038_t0058") 2020/05/15 06:24:59 DEBUG : CompareDest/two: Deleting (id "4_z9fc25d43f07d1b6b7f280e1b_f1129da7685733515_d20200515_m062026_c001_v0001036_t0037") 2020/05/15 06:24:59 DEBUG : CopyDest/one: Deleting (id "4_z9fc25d43f07d1b6b7f280e1b_f1137e31506bf9bff_d20200515_m062123_c001_v0001137_t0024") 2020/05/15 06:24:59 DEBUG : CopyDest/one: Deleting (id "4_z9fc25d43f07d1b6b7f280e1b_f115f4d5246606719_d20200515_m062038_c001_v0001113_t0040") 2020/05/15 06:24:59 DEBUG : CopyDest/three: Deleting (id "4_z9fc25d43f07d1b6b7f280e1b_f1068296156d54c67_d20200515_m062123_c001_v0001120_t0022") 2020/05/15 06:24:59 DEBUG : CopyDest/three: Deleting (id "4_z9fc25d43f07d1b6b7f280e1b_f114295255b6d45bc_d20200515_m062119_c001_v0001134_t0048") 2020/05/15 06:24:59 DEBUG : CopyDest/two: Deleting (id "4_z9fc25d43f07d1b6b7f280e1b_f1023d655d1d69a4b_d20200515_m062124_c001_v0001137_t0004") 2020/05/15 06:24:59 DEBUG : CopyDest/two: Deleting (id "4_z9fc25d43f07d1b6b7f280e1b_f1129da7685733517_d20200515_m062103_c001_v0001036_t0037") 2020/05/15 06:24:59 DEBUG : EXISTING: Deleting (id "4_z9fc25d43f07d1b6b7f280e1b_f114768723e088da2_d20200515_m062457_c001_v0001137_t0002") 2020/05/15 06:24:59 DEBUG : EXISTING: Deleting (id "4_z9fc25d43f07d1b6b7f280e1b_f115f4d52466069e7_d20200515_m062449_c001_v0001113_t0040") 2020/05/15 06:24:59 DEBUG : Testêé: Deleting (id "4_z9fc25d43f07d1b6b7f280e1b_f114295255b6d4fe4_d20200515_m062444_c001_v0001134_t0021") 2020/05/15 06:25:00 DEBUG : Testêé: Deleting (id "4_z9fc25d43f07d1b6b7f280e1b_f1129da7685733570_d20200515_m062403_c001_v0001036_t0037") 2020/05/15 06:25:00 DEBUG : Testêé: Deleting (id "4_z9fc25d43f07d1b6b7f280e1b_f115f4d524660697a_d20200515_m062400_c001_v0001113_t0040") 2020/05/15 06:25:00 DEBUG : a/potato2: Deleting (id "4_z9fc25d43f07d1b6b7f280e1b_f1017f79fa263fa70_d20200515_m061543_c001_v0001134_t0035") 2020/05/15 06:25:00 DEBUG : a/potato2: Deleting (id "4_z9fc25d43f07d1b6b7f280e1b_f115f4d5246606505_d20200515_m061524_c001_v0001113_t0040") 2020/05/15 06:25:00 DEBUG : a/potato2: Deleting (id "4_z9fc25d43f07d1b6b7f280e1b_f103d3535d0739cb4_d20200515_m061524_c001_v0001130_t0021") 2020/05/15 06:25:00 DEBUG : a/potato2: Deleting (id "4_z9fc25d43f07d1b6b7f280e1b_f109f30dad2878287_d20200515_m061521_c001_v0001136_t0017") 2020/05/15 06:25:00 DEBUG : a/potato2: Deleting (id "4_z9fc25d43f07d1b6b7f280e1b_f115f4d52466064f7_d20200515_m061519_c001_v0001113_t0040") 2020/05/15 06:25:00 DEBUG : a/potato2: Deleting (id "4_z9fc25d43f07d1b6b7f280e1b_f106e28d9b88b7092_d20200515_m061436_c001_v0001131_t0058") 2020/05/15 06:25:00 DEBUG : a/potato2: Deleting (id "4_z9fc25d43f07d1b6b7f280e1b_f115f4d5246606487_d20200515_m061435_c001_v0001113_t0040") 2020/05/15 06:25:00 DEBUG : b/potato: Deleting (id "4_z9fc25d43f07d1b6b7f280e1b_f1163c2127e3f0f0e_d20200515_m061525_c001_v0001137_t0039") 2020/05/15 06:25:00 DEBUG : b/potato: Deleting (id "4_z9fc25d43f07d1b6b7f280e1b_f115f4d52466064ff_d20200515_m061522_c001_v0001113_t0040") 2020/05/15 06:25:00 DEBUG : b/potato: Deleting (id "4_z9fc25d43f07d1b6b7f280e1b_f1009c0ecc3360783_d20200515_m061520_c001_v0001030_t0022") 2020/05/15 06:25:00 DEBUG : b/potato: Deleting (id "4_z9fc25d43f07d1b6b7f280e1b_f115f4d52466064ed_d20200515_m061518_c001_v0001113_t0040") 2020/05/15 06:25:00 DEBUG : b/potato: Deleting (id "4_z9fc25d43f07d1b6b7f280e1b_f1170c3bb24ab8e77_d20200515_m061435_c001_v0001134_t0059") 2020/05/15 06:25:00 DEBUG : b/potato: Deleting (id "4_z9fc25d43f07d1b6b7f280e1b_f115f4d5246606483_d20200515_m061433_c001_v0001113_t0040") 2020/05/15 06:25:00 DEBUG : backup/one: Deleting (id "4_z9fc25d43f07d1b6b7f280e1b_f118feb76193b8129_d20200515_m062151_c001_v0001113_t0005") 2020/05/15 06:25:00 DEBUG : backup/one: Deleting (id "4_z9fc25d43f07d1b6b7f280e1b_f105ebcc7e97c6c7e_d20200515_m062148_c001_v0001137_t0055") 2020/05/15 06:25:00 DEBUG : backup/one: Deleting (id "4_z9fc25d43f07d1b6b7f280e1b_f104df75d7c05c927_d20200515_m062132_c001_v0001042_t0042") 2020/05/15 06:25:00 DEBUG : backup/one-2019-01-01: Deleting (id "4_z9fc25d43f07d1b6b7f280e1b_f11824638a6bd0bc5_d20200515_m062254_c001_v0001120_t0046") 2020/05/15 06:25:01 DEBUG : backup/one-2019-01-01: Deleting (id "4_z9fc25d43f07d1b6b7f280e1b_f1163c2127e3f4208_d20200515_m062244_c001_v0001137_t0007") 2020/05/15 06:25:01 DEBUG : backup/one-2019-01-01: Deleting (id "4_z9fc25d43f07d1b6b7f280e1b_f109ffddfff844a72_d20200515_m062239_c001_v0001131_t0007") 2020/05/15 06:25:01 DEBUG : backup/one.bak: Deleting (id "4_z9fc25d43f07d1b6b7f280e1b_f10004978a1ec6c3e_d20200515_m062230_c001_v0001128_t0059") 2020/05/15 06:25:01 DEBUG : backup/one.bak: Deleting (id "4_z9fc25d43f07d1b6b7f280e1b_f103cc695188bb6e9_d20200515_m062224_c001_v0001134_t0025") 2020/05/15 06:25:01 DEBUG : backup/one.bak: Deleting (id "4_z9fc25d43f07d1b6b7f280e1b_f109d36d209ff92ae_d20200515_m062214_c001_v0001137_t0020") 2020/05/15 06:25:01 DEBUG : backup/three-2019-01-01.txt: Deleting (id "4_z9fc25d43f07d1b6b7f280e1b_f11652f094a929763_d20200515_m062254_c001_v0001136_t0002") 2020/05/15 06:25:01 DEBUG : backup/three-2019-01-01.txt: Deleting (id "4_z9fc25d43f07d1b6b7f280e1b_f101a5b5fadecd690_d20200515_m062252_c001_v0001137_t0052") 2020/05/15 06:25:01 DEBUG : backup/three-2019-01-01.txt: Deleting (id "4_z9fc25d43f07d1b6b7f280e1b_f103081ae0235538f_d20200515_m062241_c001_v0001030_t0009") 2020/05/15 06:25:01 DEBUG : backup/three.txt: Deleting (id "4_z9fc25d43f07d1b6b7f280e1b_f105ebcc7e97c6cc4_d20200515_m062152_c001_v0001137_t0055") 2020/05/15 06:25:01 DEBUG : backup/three.txt: Deleting (id "4_z9fc25d43f07d1b6b7f280e1b_f104f9a9ebc422f6b_d20200515_m062150_c001_v0001134_t0006") 2020/05/15 06:25:01 DEBUG : backup/three.txt: Deleting (id "4_z9fc25d43f07d1b6b7f280e1b_f1012425f50349e56_d20200515_m062146_c001_v0001093_t0019") 2020/05/15 06:25:01 DEBUG : backup/three.txt.bak: Deleting (id "4_z9fc25d43f07d1b6b7f280e1b_f114ae8c66e6954eb_d20200515_m062232_c001_v0001113_t0019") 2020/05/15 06:25:01 DEBUG : backup/three.txt.bak: Deleting (id "4_z9fc25d43f07d1b6b7f280e1b_f1167a47938519e4d_d20200515_m062229_c001_v0001092_t0050") 2020/05/15 06:25:01 DEBUG : backup/three.txt.bak: Deleting (id "4_z9fc25d43f07d1b6b7f280e1b_f117d99dd6d74fcd4_d20200515_m062221_c001_v0001137_t0051") 2020/05/15 06:25:01 DEBUG : c/non empty space: Deleting (id "4_z9fc25d43f07d1b6b7f280e1b_f1122df864364eb5b_d20200515_m061525_c001_v0001137_t0024") 2020/05/15 06:25:01 DEBUG : c/non empty space: Deleting (id "4_z9fc25d43f07d1b6b7f280e1b_f115f4d5246606503_d20200515_m061522_c001_v0001113_t0040") 2020/05/15 06:25:01 DEBUG : c/non empty space: Deleting (id "4_z9fc25d43f07d1b6b7f280e1b_f104b97f701a5804d_d20200515_m061521_c001_v0001000_t0006") 2020/05/15 06:25:01 DEBUG : c/non empty space: Deleting (id "4_z9fc25d43f07d1b6b7f280e1b_f115f4d52466064f3_d20200515_m061518_c001_v0001113_t0040") 2020/05/15 06:25:01 DEBUG : c/non empty space: Deleting (id "4_z9fc25d43f07d1b6b7f280e1b_f1067a3b5cffcbc90_d20200515_m061437_c001_v0001134_t0025") 2020/05/15 06:25:01 DEBUG : c/non empty space: Deleting (id "4_z9fc25d43f07d1b6b7f280e1b_f115f4d5246606485_d20200515_m061434_c001_v0001113_t0040") 2020/05/15 06:25:01 DEBUG : check sum: Deleting (id "4_z9fc25d43f07d1b6b7f280e1b_f115235bdbb2e02c4_d20200515_m061417_c001_v0001134_t0044") 2020/05/15 06:25:02 DEBUG : check sum: Deleting (id "4_z9fc25d43f07d1b6b7f280e1b_f115f4d524660646d_d20200515_m061416_c001_v0001113_t0040") 2020/05/15 06:25:02 DEBUG : dst/one: Deleting (id "4_z9fc25d43f07d1b6b7f280e1b_f1081f7458cd6ba28_d20200515_m062349_c001_v0001040_t0009") 2020/05/15 06:25:02 DEBUG : dst/one: Deleting (id "4_z9fc25d43f07d1b6b7f280e1b_f102e78636b995721_d20200515_m062346_c001_v0001134_t0018") 2020/05/15 06:25:02 DEBUG : dst/one: Deleting (id "4_z9fc25d43f07d1b6b7f280e1b_f1017f79fa26422c0_d20200515_m062345_c001_v0001134_t0030") 2020/05/15 06:25:02 DEBUG : dst/one: Deleting (id "4_z9fc25d43f07d1b6b7f280e1b_f102e78636b9956a4_d20200515_m062340_c001_v0001134_t0018") 2020/05/15 06:25:02 DEBUG : dst/one: Deleting (id "4_z9fc25d43f07d1b6b7f280e1b_f10888b12a8613976_d20200515_m062339_c001_v0001137_t0007") 2020/05/15 06:25:02 DEBUG : dst/one: Deleting (id "4_z9fc25d43f07d1b6b7f280e1b_f115f4d524660692b_d20200515_m062325_c001_v0001113_t0040") 2020/05/15 06:25:02 DEBUG : dst/one: Deleting (id "4_z9fc25d43f07d1b6b7f280e1b_f110db7203dfe3d42_d20200515_m062322_c001_v0001128_t0059") 2020/05/15 06:25:02 DEBUG : dst/one: Deleting (id "4_z9fc25d43f07d1b6b7f280e1b_f114295255b6d4bb8_d20200515_m062310_c001_v0001134_t0025") 2020/05/15 06:25:02 DEBUG : dst/one: Deleting (id "4_z9fc25d43f07d1b6b7f280e1b_f101a5b5fadecd796_d20200515_m062309_c001_v0001137_t0041") 2020/05/15 06:25:02 DEBUG : dst/one: Deleting (id "4_z9fc25d43f07d1b6b7f280e1b_f114295255b6d4b4c_d20200515_m062302_c001_v0001134_t0025") 2020/05/15 06:25:02 DEBUG : dst/one: Deleting (id "4_z9fc25d43f07d1b6b7f280e1b_f1023d655d1d6a053_d20200515_m062301_c001_v0001137_t0028") 2020/05/15 06:25:02 DEBUG : dst/one: Deleting (id "4_z9fc25d43f07d1b6b7f280e1b_f115f4d52466068ef_d20200515_m062256_c001_v0001113_t0040") 2020/05/15 06:25:02 DEBUG : dst/one: Deleting (id "4_z9fc25d43f07d1b6b7f280e1b_f1116678cbf8789f9_d20200515_m062255_c001_v0001092_t0005") 2020/05/15 06:25:02 DEBUG : dst/one: Deleting (id "4_z9fc25d43f07d1b6b7f280e1b_f109be49a3b540677_d20200515_m062250_c001_v0001033_t0026") 2020/05/15 06:25:02 DEBUG : dst/one: Deleting (id "4_z9fc25d43f07d1b6b7f280e1b_f11805f796fd9b6ad_d20200515_m062248_c001_v0001038_t0029") 2020/05/15 06:25:02 DEBUG : dst/one: Deleting (id "4_z9fc25d43f07d1b6b7f280e1b_f109be49a3b540672_d20200515_m062240_c001_v0001033_t0026") 2020/05/15 06:25:02 DEBUG : dst/one: Deleting (id "4_z9fc25d43f07d1b6b7f280e1b_f103cc695188bb7c1_d20200515_m062239_c001_v0001134_t0032") 2020/05/15 06:25:02 DEBUG : dst/one: Deleting (id "4_z9fc25d43f07d1b6b7f280e1b_f114295255b6d4a0b_d20200515_m062234_c001_v0001134_t0048") 2020/05/15 06:25:02 DEBUG : dst/one: Deleting (id "4_z9fc25d43f07d1b6b7f280e1b_f107d445bea6a3268_d20200515_m062233_c001_v0001137_t0044") 2020/05/15 06:25:03 DEBUG : dst/one: Deleting (id "4_z9fc25d43f07d1b6b7f280e1b_f104fb0ce7cbe0341_d20200515_m062225_c001_v0001040_t0026") 2020/05/15 06:25:03 DEBUG : dst/one: Deleting (id "4_z9fc25d43f07d1b6b7f280e1b_f107f5234d376f1d4_d20200515_m062224_c001_v0001091_t0016") 2020/05/15 06:25:03 DEBUG : dst/one: Deleting (id "4_z9fc25d43f07d1b6b7f280e1b_f104fb0ce7cbe033b_d20200515_m062216_c001_v0001040_t0026") 2020/05/15 06:25:03 DEBUG : dst/one: Deleting (id "4_z9fc25d43f07d1b6b7f280e1b_f106e7974c598887c_d20200515_m062215_c001_v0001137_t0023") 2020/05/15 06:25:03 DEBUG : dst/one: Deleting (id "4_z9fc25d43f07d1b6b7f280e1b_f1129da7685733536_d20200515_m062154_c001_v0001036_t0037") 2020/05/15 06:25:03 DEBUG : dst/one: Deleting (id "4_z9fc25d43f07d1b6b7f280e1b_f101ffa979bcd5532_d20200515_m062152_c001_v0001033_t0042") 2020/05/15 06:25:03 DEBUG : dst/one: Deleting (id "4_z9fc25d43f07d1b6b7f280e1b_f10388cdfe3686268_d20200515_m062150_c001_v0001033_t0055") 2020/05/15 06:25:03 DEBUG : dst/one: Deleting (id "4_z9fc25d43f07d1b6b7f280e1b_f1062fb53478a30e8_d20200515_m062149_c001_v0001136_t0058") 2020/05/15 06:25:03 DEBUG : dst/one: Deleting (id "4_z9fc25d43f07d1b6b7f280e1b_f10388cdfe368623b_d20200515_m062133_c001_v0001033_t0055") 2020/05/15 06:25:03 DEBUG : dst/one: Deleting (id "4_z9fc25d43f07d1b6b7f280e1b_f115aae65fc9adfd4_d20200515_m062132_c001_v0001031_t0031") 2020/05/15 06:25:03 DEBUG : dst/one: Deleting (id "4_z9fc25d43f07d1b6b7f280e1b_f115f4d52466067a2_d20200515_m062128_c001_v0001113_t0040") 2020/05/15 06:25:03 DEBUG : dst/one: Deleting (id "4_z9fc25d43f07d1b6b7f280e1b_f1062fb53478a2eec_d20200515_m062125_c001_v0001136_t0058") 2020/05/15 06:25:03 DEBUG : dst/one: Deleting (id "4_z9fc25d43f07d1b6b7f280e1b_f11840c3dce86e8e6_d20200515_m062102_c001_v0001137_t0037") 2020/05/15 06:25:03 DEBUG : dst/one: Deleting (id "4_z9fc25d43f07d1b6b7f280e1b_f1164a04d8e9c544a_d20200515_m062041_c001_v0001090_t0057") 2020/05/15 06:25:03 DEBUG : dst/one: Deleting (id "4_z9fc25d43f07d1b6b7f280e1b_f114295255b6d435f_d20200515_m062037_c001_v0001134_t0048") 2020/05/15 06:25:03 DEBUG : dst/one: Deleting (id "4_z9fc25d43f07d1b6b7f280e1b_f1023d655d1d69757_d20200515_m062036_c001_v0001137_t0043") 2020/05/15 06:25:03 DEBUG : dst/one: Deleting (id "4_z9fc25d43f07d1b6b7f280e1b_f1023d655d1d6974f_d20200515_m062034_c001_v0001137_t0043") 2020/05/15 06:25:03 DEBUG : dst/one: Deleting (id "4_z9fc25d43f07d1b6b7f280e1b_f109f30dad2879754_d20200515_m062031_c001_v0001136_t0026") 2020/05/15 06:25:03 DEBUG : dst/one: Deleting (id "4_z9fc25d43f07d1b6b7f280e1b_f114295255b6d42c6_d20200515_m062024_c001_v0001134_t0048") 2020/05/15 06:25:03 DEBUG : dst/one: Deleting (id "4_z9fc25d43f07d1b6b7f280e1b_f1023d655d1d696b9_d20200515_m062023_c001_v0001137_t0008") 2020/05/15 06:25:03 DEBUG : dst/one: Deleting (id "4_z9fc25d43f07d1b6b7f280e1b_f1023d655d1d6969e_d20200515_m062021_c001_v0001137_t0008") 2020/05/15 06:25:03 DEBUG : dst/one-2019-01-01: Deleting (id "4_z9fc25d43f07d1b6b7f280e1b_f108addb697cbbf0d_d20200515_m062355_c001_v0001136_t0016") 2020/05/15 06:25:03 DEBUG : dst/one-2019-01-01: Deleting (id "4_z9fc25d43f07d1b6b7f280e1b_f11492e768df2e6e1_d20200515_m062345_c001_v0001004_t0031") 2020/05/15 06:25:03 DEBUG : dst/one-2019-01-01: Deleting (id "4_z9fc25d43f07d1b6b7f280e1b_f110deb1e51d48025_d20200515_m062333_c001_v0001092_t0057") 2020/05/15 06:25:03 DEBUG : dst/one.bak: Deleting (id "4_z9fc25d43f07d1b6b7f280e1b_f1163c2127e3f4608_d20200515_m062323_c001_v0001137_t0016") 2020/05/15 06:25:04 DEBUG : dst/one.bak: Deleting (id "4_z9fc25d43f07d1b6b7f280e1b_f10948238ab52fefb_d20200515_m062307_c001_v0001134_t0046") 2020/05/15 06:25:04 DEBUG : dst/one.bak: Deleting (id "4_z9fc25d43f07d1b6b7f280e1b_f1122df8643651e67_d20200515_m062300_c001_v0001137_t0007") 2020/05/15 06:25:04 DEBUG : dst/three: Deleting (id "4_z9fc25d43f07d1b6b7f280e1b_f105163960384470e_d20200515_m062125_c001_v0001134_t0052") 2020/05/15 06:25:04 DEBUG : dst/three: Deleting (id "4_z9fc25d43f07d1b6b7f280e1b_f1023d655d1d69a22_d20200515_m062120_c001_v0001137_t0043") 2020/05/15 06:25:04 DEBUG : dst/three-2019-01-01.txt: Deleting (id "4_z9fc25d43f07d1b6b7f280e1b_f110f800716416285_d20200515_m062358_c001_v0001137_t0053") 2020/05/15 06:25:04 DEBUG : dst/three-2019-01-01.txt: Deleting (id "4_z9fc25d43f07d1b6b7f280e1b_f110febbcec5acfa6_d20200515_m062347_c001_v0001136_t0028") 2020/05/15 06:25:04 DEBUG : dst/three-2019-01-01.txt: Deleting (id "4_z9fc25d43f07d1b6b7f280e1b_f1192345ec07ae0c8_d20200515_m062341_c001_v0001137_t0036") 2020/05/15 06:25:04 DEBUG : dst/three.txt: Deleting (id "4_z9fc25d43f07d1b6b7f280e1b_f110578923b662e59_d20200515_m062359_c001_v0001044_t0001") 2020/05/15 06:25:04 DEBUG : dst/three.txt: Deleting (id "4_z9fc25d43f07d1b6b7f280e1b_f102e78636b99573b_d20200515_m062348_c001_v0001134_t0018") 2020/05/15 06:25:04 DEBUG : dst/three.txt: Deleting (id "4_z9fc25d43f07d1b6b7f280e1b_f1192345ec07ae171_d20200515_m062348_c001_v0001137_t0059") 2020/05/15 06:25:04 DEBUG : dst/three.txt: Deleting (id "4_z9fc25d43f07d1b6b7f280e1b_f102e78636b9956da_d20200515_m062343_c001_v0001134_t0018") 2020/05/15 06:25:04 DEBUG : dst/three.txt: Deleting (id "4_z9fc25d43f07d1b6b7f280e1b_f109d36d209ff97a4_d20200515_m062342_c001_v0001137_t0018") 2020/05/15 06:25:04 DEBUG : dst/three.txt: Deleting (id "4_z9fc25d43f07d1b6b7f280e1b_f114295255b6d4ca5_d20200515_m062331_c001_v0001134_t0048") 2020/05/15 06:25:04 DEBUG : dst/three.txt: Deleting (id "4_z9fc25d43f07d1b6b7f280e1b_f111f55f240e841e5_d20200515_m062314_c001_v0001033_t0049") 2020/05/15 06:25:04 DEBUG : dst/three.txt: Deleting (id "4_z9fc25d43f07d1b6b7f280e1b_f114295255b6d4bf7_d20200515_m062314_c001_v0001134_t0025") 2020/05/15 06:25:04 DEBUG : dst/three.txt: Deleting (id "4_z9fc25d43f07d1b6b7f280e1b_f114295255b6d4b6b_d20200515_m062304_c001_v0001134_t0025") 2020/05/15 06:25:04 DEBUG : dst/three.txt: Deleting (id "4_z9fc25d43f07d1b6b7f280e1b_f1017f79fa2641fa8_d20200515_m062304_c001_v0001134_t0053") 2020/05/15 06:25:04 DEBUG : dst/three.txt: Deleting (id "4_z9fc25d43f07d1b6b7f280e1b_f114295255b6d4b1f_d20200515_m062258_c001_v0001134_t0048") 2020/05/15 06:25:04 DEBUG : dst/three.txt: Deleting (id "4_z9fc25d43f07d1b6b7f280e1b_f105ebcc7e97c7147_d20200515_m062253_c001_v0001137_t0047") 2020/05/15 06:25:04 DEBUG : dst/three.txt: Deleting (id "4_z9fc25d43f07d1b6b7f280e1b_f114295255b6d4a66_d20200515_m062243_c001_v0001134_t0048") 2020/05/15 06:25:04 DEBUG : dst/three.txt: Deleting (id "4_z9fc25d43f07d1b6b7f280e1b_f108addb697cbbb7e_d20200515_m062241_c001_v0001136_t0013") 2020/05/15 06:25:04 DEBUG : dst/three.txt: Deleting (id "4_z9fc25d43f07d1b6b7f280e1b_f1129da768573354d_d20200515_m062236_c001_v0001036_t0037") 2020/05/15 06:25:04 DEBUG : dst/three.txt: Deleting (id "4_z9fc25d43f07d1b6b7f280e1b_f1088ce6c1fb07ebc_d20200515_m062229_c001_v0001134_t0045") 2020/05/15 06:25:04 DEBUG : dst/three.txt: Deleting (id "4_z9fc25d43f07d1b6b7f280e1b_f1129da7685733548_d20200515_m062223_c001_v0001036_t0037") 2020/05/15 06:25:05 DEBUG : dst/three.txt: Deleting (id "4_z9fc25d43f07d1b6b7f280e1b_f109792c2974bef3f_d20200515_m062222_c001_v0001031_t0027") 2020/05/15 06:25:05 DEBUG : dst/three.txt: Deleting (id "4_z9fc25d43f07d1b6b7f280e1b_f115f4d524660685f_d20200515_m062211_c001_v0001113_t0040") 2020/05/15 06:25:05 DEBUG : dst/three.txt: Deleting (id "4_z9fc25d43f07d1b6b7f280e1b_f113435d251c0463f_d20200515_m062151_c001_v0001134_t0045") 2020/05/15 06:25:05 DEBUG : dst/three.txt: Deleting (id "4_z9fc25d43f07d1b6b7f280e1b_f115f4d52466067fc_d20200515_m062147_c001_v0001113_t0040") 2020/05/15 06:25:05 DEBUG : dst/three.txt: Deleting (id "4_z9fc25d43f07d1b6b7f280e1b_f114a518a8b38f817_d20200515_m062146_c001_v0001026_t0026") 2020/05/15 06:25:05 DEBUG : dst/three.txt: Deleting (id "4_z9fc25d43f07d1b6b7f280e1b_f114295255b6d4665_d20200515_m062130_c001_v0001134_t0048") 2020/05/15 06:25:05 DEBUG : dst/three.txt.bak: Deleting (id "4_z9fc25d43f07d1b6b7f280e1b_f114ee1e30f2bd18e_d20200515_m062323_c001_v0001130_t0047") 2020/05/15 06:25:05 DEBUG : dst/three.txt.bak: Deleting (id "4_z9fc25d43f07d1b6b7f280e1b_f104d3eb04fbd10a3_d20200515_m062312_c001_v0001136_t0050") 2020/05/15 06:25:05 DEBUG : dst/three.txt.bak: Deleting (id "4_z9fc25d43f07d1b6b7f280e1b_f108a74353681cf43_d20200515_m062303_c001_v0001131_t0005") 2020/05/15 06:25:05 DEBUG : dst/two: Deleting (id "4_z9fc25d43f07d1b6b7f280e1b_f112d881787bb988c_d20200515_m062359_c001_v0001044_t0010") 2020/05/15 06:25:05 DEBUG : dst/two: Deleting (id "4_z9fc25d43f07d1b6b7f280e1b_f1129da7685733568_d20200515_m062328_c001_v0001036_t0037") 2020/05/15 06:25:05 DEBUG : dst/two: Deleting (id "4_z9fc25d43f07d1b6b7f280e1b_f109d36d209ff96a3_d20200515_m062323_c001_v0001137_t0004") 2020/05/15 06:25:05 DEBUG : dst/two: Deleting (id "4_z9fc25d43f07d1b6b7f280e1b_f1129da7685733555_d20200515_m062257_c001_v0001036_t0037") 2020/05/15 06:25:05 DEBUG : dst/two: Deleting (id "4_z9fc25d43f07d1b6b7f280e1b_f107d23556f386abd_d20200515_m062255_c001_v0001033_t0027") 2020/05/15 06:25:05 DEBUG : dst/two: Deleting (id "4_z9fc25d43f07d1b6b7f280e1b_f115f4d52466068ab_d20200515_m062235_c001_v0001113_t0040") 2020/05/15 06:25:05 DEBUG : dst/two: Deleting (id "4_z9fc25d43f07d1b6b7f280e1b_f111f55f240e841d0_d20200515_m062233_c001_v0001033_t0036") 2020/05/15 06:25:05 DEBUG : dst/two: Deleting (id "4_z9fc25d43f07d1b6b7f280e1b_f114295255b6d48e4_d20200515_m062210_c001_v0001134_t0048") 2020/05/15 06:25:05 DEBUG : dst/two: Deleting (id "4_z9fc25d43f07d1b6b7f280e1b_f11937c7da8629f08_d20200515_m062153_c001_v0001134_t0040") 2020/05/15 06:25:05 DEBUG : dst/two: Deleting (id "4_z9fc25d43f07d1b6b7f280e1b_f1129da7685733525_d20200515_m062129_c001_v0001036_t0037") 2020/05/15 06:25:05 DEBUG : dst/two: Deleting (id "4_z9fc25d43f07d1b6b7f280e1b_f115235bdbb2e2681_d20200515_m062127_c001_v0001134_t0017") 2020/05/15 06:25:05 DEBUG : dst/two: Deleting (id "4_z9fc25d43f07d1b6b7f280e1b_f105163960384467f_d20200515_m062117_c001_v0001134_t0053") 2020/05/15 06:25:05 DEBUG : dst/two: Deleting (id "4_z9fc25d43f07d1b6b7f280e1b_f1179a23084a6210a_d20200515_m062032_c001_v0001136_t0032") 2020/05/15 06:25:05 DEBUG : dst/two: Deleting (id "4_z9fc25d43f07d1b6b7f280e1b_f1023d655d1d69703_d20200515_m062029_c001_v0001137_t0008") 2020/05/15 06:25:05 DEBUG : empty space: Deleting (id "4_z9fc25d43f07d1b6b7f280e1b_f1068296156d54c1f_d20200515_m061928_c001_v0001120_t0012") 2020/05/15 06:25:06 DEBUG : empty space: Deleting (id "4_z9fc25d43f07d1b6b7f280e1b_f114295255b6d3f9c_d20200515_m061921_c001_v0001134_t0048") 2020/05/15 06:25:06 DEBUG : empty space: Deleting (id "4_z9fc25d43f07d1b6b7f280e1b_f10388cdfe36860df_d20200515_m061839_c001_v0001033_t0027") 2020/05/15 06:25:06 DEBUG : empty space: Deleting (id "4_z9fc25d43f07d1b6b7f280e1b_f114295255b6d3ce3_d20200515_m061826_c001_v0001134_t0048") 2020/05/15 06:25:06 DEBUG : empty space: Deleting (id "4_z9fc25d43f07d1b6b7f280e1b_f118566074b5e8c58_d20200515_m061815_c001_v0001041_t0045") 2020/05/15 06:25:06 DEBUG : empty space: Deleting (id "4_z9fc25d43f07d1b6b7f280e1b_f114295255b6d3a77_d20200515_m061740_c001_v0001134_t0048") 2020/05/15 06:25:06 DEBUG : empty space: Deleting (id "4_z9fc25d43f07d1b6b7f280e1b_f107ec094306400cc_d20200515_m061622_c001_v0001130_t0049") 2020/05/15 06:25:06 DEBUG : empty space: Deleting (id "4_z9fc25d43f07d1b6b7f280e1b_f115f4d524660655f_d20200515_m061619_c001_v0001113_t0040") 2020/05/15 06:25:06 DEBUG : empty space: Deleting (id "4_z9fc25d43f07d1b6b7f280e1b_f118278fdab4f893c_d20200515_m061615_c001_v0001134_t0026") 2020/05/15 06:25:06 DEBUG : empty space: Deleting (id "4_z9fc25d43f07d1b6b7f280e1b_f115f4d5246606557_d20200515_m061613_c001_v0001113_t0040") 2020/05/15 06:25:06 DEBUG : empty space: Deleting (id "4_z9fc25d43f07d1b6b7f280e1b_f103cc695188ba0cd_d20200515_m061551_c001_v0001134_t0009") 2020/05/15 06:25:06 DEBUG : empty space: Deleting (id "4_z9fc25d43f07d1b6b7f280e1b_f115f4d5246606528_d20200515_m061548_c001_v0001113_t0040") 2020/05/15 06:25:06 DEBUG : empty space: Deleting (id "4_z9fc25d43f07d1b6b7f280e1b_f1192345ec07ab387_d20200515_m061545_c001_v0001137_t0005") 2020/05/15 06:25:06 DEBUG : empty space: Deleting (id "4_z9fc25d43f07d1b6b7f280e1b_f115f4d5246606518_d20200515_m061534_c001_v0001113_t0040") 2020/05/15 06:25:06 DEBUG : empty space: Deleting (id "4_z9fc25d43f07d1b6b7f280e1b_f11652f094a927d72_d20200515_m061516_c001_v0001136_t0011") 2020/05/15 06:25:06 DEBUG : empty space: Deleting (id "4_z9fc25d43f07d1b6b7f280e1b_f115f4d52466064e7_d20200515_m061514_c001_v0001113_t0040") 2020/05/15 06:25:06 DEBUG : empty space: Deleting (id "4_z9fc25d43f07d1b6b7f280e1b_f1196a63ed791f824_d20200515_m061510_c001_v0001128_t0029") 2020/05/15 06:25:06 DEBUG : empty space: Deleting (id "4_z9fc25d43f07d1b6b7f280e1b_f115f4d52466064d9_d20200515_m061508_c001_v0001113_t0040") 2020/05/15 06:25:06 DEBUG : empty space: Deleting (id "4_z9fc25d43f07d1b6b7f280e1b_f107d445bea69f5cf_d20200515_m061500_c001_v0001137_t0023") 2020/05/15 06:25:06 DEBUG : empty space: Deleting (id "4_z9fc25d43f07d1b6b7f280e1b_f115f4d52466064b5_d20200515_m061458_c001_v0001113_t0040") 2020/05/15 06:25:06 DEBUG : empty space: Deleting (id "4_z9fc25d43f07d1b6b7f280e1b_f11073aba2caaef42_d20200515_m061450_c001_v0001036_t0039") 2020/05/15 06:25:06 DEBUG : empty space: Deleting (id "4_z9fc25d43f07d1b6b7f280e1b_f115f4d524660649e_d20200515_m061448_c001_v0001113_t0040") 2020/05/15 06:25:06 DEBUG : empty space: Deleting (id "4_z9fc25d43f07d1b6b7f280e1b_f1163c2127e3f0a5c_d20200515_m061439_c001_v0001137_t0010") 2020/05/15 06:25:06 DEBUG : empty space: Deleting (id "4_z9fc25d43f07d1b6b7f280e1b_f115a3c23d2e40316_d20200515_m061439_c001_v0001137_t0015") 2020/05/15 06:25:06 DEBUG : empty space: Deleting (id "4_z9fc25d43f07d1b6b7f280e1b_f115f4d524660648c_d20200515_m061437_c001_v0001113_t0040") 2020/05/15 06:25:07 DEBUG : enormous: Deleting (id "4_z9fc25d43f07d1b6b7f280e1b_f1192345ec07ab6bd_d20200515_m061621_c001_v0001137_t0002") 2020/05/15 06:25:07 DEBUG : enormous: Deleting (id "4_z9fc25d43f07d1b6b7f280e1b_f115f4d5246606563_d20200515_m061620_c001_v0001113_t0040") 2020/05/15 06:25:07 DEBUG : existing: Deleting (id "4_z9fc25d43f07d1b6b7f280e1b_f110d5f6bbfa26319_d20200515_m062447_c001_v0001134_t0055") 2020/05/15 06:25:07 DEBUG : existing: Deleting (id "4_z9fc25d43f07d1b6b7f280e1b_f114295255b6d4ff4_d20200515_m062445_c001_v0001134_t0048") 2020/05/15 06:25:07 DEBUG : existing: Deleting (id "4_z9fc25d43f07d1b6b7f280e1b_f101fceef9a862d99_d20200515_m061432_c001_v0001136_t0006") 2020/05/15 06:25:07 DEBUG : existing: Deleting (id "4_z9fc25d43f07d1b6b7f280e1b_f115f4d5246606477_d20200515_m061423_c001_v0001113_t0040") 2020/05/15 06:25:07 DEBUG : existing: Deleting (id "4_z9fc25d43f07d1b6b7f280e1b_f1023d655d1d68113_d20200515_m061423_c001_v0001137_t0014") 2020/05/15 06:25:07 DEBUG : existing: Deleting (id "4_z9fc25d43f07d1b6b7f280e1b_f115f4d5246606475_d20200515_m061421_c001_v0001113_t0040") 2020/05/15 06:25:07 DEBUG : five: Deleting (id "4_z9fc25d43f07d1b6b7f280e1b_f101257f7b0b55108_d20200515_m061642_c001_v0001044_t0004") 2020/05/15 06:25:07 DEBUG : five: Deleting (id "4_z9fc25d43f07d1b6b7f280e1b_f115f4d5246606573_d20200515_m061625_c001_v0001113_t0040") 2020/05/15 06:25:07 DEBUG : foo: Deleting (id "4_z9fc25d43f07d1b6b7f280e1b_f10888b12a8610e75_d20200515_m061457_c001_v0001137_t0004") 2020/05/15 06:25:07 DEBUG : foo: Deleting (id "4_z9fc25d43f07d1b6b7f280e1b_f115f4d52466064aa_d20200515_m061452_c001_v0001113_t0040") 2020/05/15 06:25:07 DEBUG : foo: Deleting (id "4_z9fc25d43f07d1b6b7f280e1b_f115f4d52466064a8_d20200515_m061450_c001_v0001113_t0040") 2020/05/15 06:25:07 DEBUG : four: Deleting (id "4_z9fc25d43f07d1b6b7f280e1b_f105eb3feae2ab11f_d20200515_m061643_c001_v0001136_t0024") 2020/05/15 06:25:07 DEBUG : four: Deleting (id "4_z9fc25d43f07d1b6b7f280e1b_f1129da768573348c_d20200515_m061625_c001_v0001036_t0037") 2020/05/15 06:25:07 DEBUG : four: Deleting (id "4_z9fc25d43f07d1b6b7f280e1b_f115f4d5246606571_d20200515_m061624_c001_v0001113_t0040") 2020/05/15 06:25:07 DEBUG : hello world2: Deleting (id "4_z9fc25d43f07d1b6b7f280e1b_f109f30dad2877c3a_d20200515_m061351_c001_v0001136_t0038") 2020/05/15 06:25:07 DEBUG : hello world2: Deleting (id "4_z9fc25d43f07d1b6b7f280e1b_f115f4d5246606419_d20200515_m061342_c001_v0001113_t0040") 2020/05/15 06:25:07 DEBUG : ignore-size: Deleting (id "4_z9fc25d43f07d1b6b7f280e1b_f119844f30766b6da_d20200515_m061421_c001_v0001091_t0003") 2020/05/15 06:25:07 DEBUG : ignore-size: Deleting (id "4_z9fc25d43f07d1b6b7f280e1b_f115f4d5246606471_d20200515_m061420_c001_v0001113_t0040") 2020/05/15 06:25:07 DEBUG : nested/sub dir/file: Deleting (id "4_z9fc25d43f07d1b6b7f280e1b_f100a91f0ddcfb2f5_d20200515_m061701_c001_v0001113_t0045") 2020/05/15 06:25:07 DEBUG : nested/sub dir/file: Deleting (id "4_z9fc25d43f07d1b6b7f280e1b_f115f4d52466065ad_d20200515_m061657_c001_v0001113_t0040") 2020/05/15 06:25:07 DEBUG : nested/sub dir/file: Deleting (id "4_z9fc25d43f07d1b6b7f280e1b_f108ef3c3753e4d7f_d20200515_m061655_c001_v0001113_t0023") 2020/05/15 06:25:07 DEBUG : nested/sub dir/file: Deleting (id "4_z9fc25d43f07d1b6b7f280e1b_f114295255b6d3829_d20200515_m061654_c001_v0001134_t0048") 2020/05/15 06:25:07 DEBUG : one: Deleting (id "4_z9fc25d43f07d1b6b7f280e1b_f11141cf9af5d9d99_d20200515_m061643_c001_v0001134_t0002") 2020/05/15 06:25:08 DEBUG : one: Deleting (id "4_z9fc25d43f07d1b6b7f280e1b_f115f4d5246606567_d20200515_m061623_c001_v0001113_t0040") 2020/05/15 06:25:08 DEBUG : potato: Deleting (id "4_z9fc25d43f07d1b6b7f280e1b_f1014902513310180_d20200515_m061653_c001_v0001113_t0021") 2020/05/15 06:25:08 DEBUG : potato: Deleting (id "4_z9fc25d43f07d1b6b7f280e1b_f115f4d52466065a2_d20200515_m061650_c001_v0001113_t0040") 2020/05/15 06:25:08 DEBUG : potato: Deleting (id "4_z9fc25d43f07d1b6b7f280e1b_f118ee8a7d7d57d93_d20200515_m061648_c001_v0001136_t0037") 2020/05/15 06:25:08 DEBUG : potato: Deleting (id "4_z9fc25d43f07d1b6b7f280e1b_f1129da768573349a_d20200515_m061645_c001_v0001036_t0037") 2020/05/15 06:25:08 DEBUG : potato: Deleting (id "4_z9fc25d43f07d1b6b7f280e1b_f118278fdab4f88b6_d20200515_m061608_c001_v0001134_t0034") 2020/05/15 06:25:08 DEBUG : potato: Deleting (id "4_z9fc25d43f07d1b6b7f280e1b_f115f4d5246606531_d20200515_m061552_c001_v0001113_t0040") 2020/05/15 06:25:08 DEBUG : potato: Deleting (id "4_z9fc25d43f07d1b6b7f280e1b_f1005d6a42904ac61_d20200515_m061549_c001_v0001136_t0036") 2020/05/15 06:25:08 DEBUG : potato: Deleting (id "4_z9fc25d43f07d1b6b7f280e1b_f115f4d5246606526_d20200515_m061546_c001_v0001113_t0040") 2020/05/15 06:25:08 DEBUG : potato: Deleting (id "4_z9fc25d43f07d1b6b7f280e1b_f10967747e69cb0bc_d20200515_m061543_c001_v0001128_t0049") 2020/05/15 06:25:08 DEBUG : potato: Deleting (id "4_z9fc25d43f07d1b6b7f280e1b_f115f4d5246606516_d20200515_m061534_c001_v0001113_t0040") 2020/05/15 06:25:08 DEBUG : potato: Deleting (id "4_z9fc25d43f07d1b6b7f280e1b_f116a8830745bc985_d20200515_m061515_c001_v0001134_t0054") 2020/05/15 06:25:08 DEBUG : potato: Deleting (id "4_z9fc25d43f07d1b6b7f280e1b_f115f4d52466064e5_d20200515_m061513_c001_v0001113_t0040") 2020/05/15 06:25:08 DEBUG : potato: Deleting (id "4_z9fc25d43f07d1b6b7f280e1b_f1157ba13d9493ca6_d20200515_m061512_c001_v0001136_t0057") 2020/05/15 06:25:08 DEBUG : potato: Deleting (id "4_z9fc25d43f07d1b6b7f280e1b_f115f4d52466064d7_d20200515_m061508_c001_v0001113_t0040") 2020/05/15 06:25:08 DEBUG : potato: Deleting (id "4_z9fc25d43f07d1b6b7f280e1b_f102685082f244abd_d20200515_m061507_c001_v0001091_t0031") 2020/05/15 06:25:08 DEBUG : potato: Deleting (id "4_z9fc25d43f07d1b6b7f280e1b_f115f4d52466064d3_d20200515_m061506_c001_v0001113_t0040") 2020/05/15 06:25:08 DEBUG : potato: Deleting (id "4_z9fc25d43f07d1b6b7f280e1b_f115f4d52466064d1_d20200515_m061505_c001_v0001113_t0040") 2020/05/15 06:25:08 DEBUG : potato: Deleting (id "4_z9fc25d43f07d1b6b7f280e1b_f10888b12a8610f1c_d20200515_m061504_c001_v0001137_t0005") 2020/05/15 06:25:08 DEBUG : potato: Deleting (id "4_z9fc25d43f07d1b6b7f280e1b_f115f4d52466064cc_d20200515_m061503_c001_v0001113_t0040") 2020/05/15 06:25:08 DEBUG : potato: Deleting (id "4_z9fc25d43f07d1b6b7f280e1b_f115f4d52466064c1_d20200515_m061502_c001_v0001113_t0040") 2020/05/15 06:25:08 DEBUG : potato: Deleting (id "4_z9fc25d43f07d1b6b7f280e1b_f119586cb9b40132e_d20200515_m061501_c001_v0001042_t0009") 2020/05/15 06:25:08 DEBUG : potato: Deleting (id "4_z9fc25d43f07d1b6b7f280e1b_f115f4d52466064bb_d20200515_m061459_c001_v0001113_t0040") 2020/05/15 06:25:08 DEBUG : potato2: Deleting (id "4_z9fc25d43f07d1b6b7f280e1b_f118278fdab4f9a65_d20200515_m062017_c001_v0001134_t0041") 2020/05/15 06:25:08 DEBUG : potato2: Deleting (id "4_z9fc25d43f07d1b6b7f280e1b_f1129da7685733504_d20200515_m061936_c001_v0001036_t0037") 2020/05/15 06:25:09 DEBUG : potato2: Deleting (id "4_z9fc25d43f07d1b6b7f280e1b_f115235bdbb2e1dd0_d20200515_m061928_c001_v0001134_t0048") 2020/05/15 06:25:09 DEBUG : potato2: Deleting (id "4_z9fc25d43f07d1b6b7f280e1b_f1129da76857334e6_d20200515_m061840_c001_v0001036_t0037") 2020/05/15 06:25:09 DEBUG : potato2: Deleting (id "4_z9fc25d43f07d1b6b7f280e1b_f1006c2c426142bf8_d20200515_m061832_c001_v0001137_t0024") 2020/05/15 06:25:09 DEBUG : potato2: Deleting (id "4_z9fc25d43f07d1b6b7f280e1b_f1129da76857334d0_d20200515_m061825_c001_v0001036_t0037") 2020/05/15 06:25:09 DEBUG : potato2: Deleting (id "4_z9fc25d43f07d1b6b7f280e1b_f104d3eb04fbcf9b7_d20200515_m061745_c001_v0001136_t0017") 2020/05/15 06:25:09 DEBUG : potato2: Deleting (id "4_z9fc25d43f07d1b6b7f280e1b_f1129da76857334a2_d20200515_m061703_c001_v0001036_t0037") 2020/05/15 06:25:09 DEBUG : potato2: Deleting (id "4_z9fc25d43f07d1b6b7f280e1b_f118278fdab4f89e6_d20200515_m061622_c001_v0001134_t0043") 2020/05/15 06:25:09 DEBUG : potato2: Deleting (id "4_z9fc25d43f07d1b6b7f280e1b_f115f4d5246606559_d20200515_m061618_c001_v0001113_t0040") 2020/05/15 06:25:09 DEBUG : potato2: Deleting (id "4_z9fc25d43f07d1b6b7f280e1b_f10408141a8df4da5_d20200515_m061615_c001_v0001137_t0044") 2020/05/15 06:25:09 DEBUG : potato2: Deleting (id "4_z9fc25d43f07d1b6b7f280e1b_f115f4d524660654f_d20200515_m061610_c001_v0001113_t0040") 2020/05/15 06:25:09 DEBUG : potato2: Deleting (id "4_z9fc25d43f07d1b6b7f280e1b_f111c120e75132c6c_d20200515_m061609_c001_v0001136_t0025") 2020/05/15 06:25:09 DEBUG : potato2: Deleting (id "4_z9fc25d43f07d1b6b7f280e1b_f115f4d524660653f_d20200515_m061600_c001_v0001113_t0040") 2020/05/15 06:25:09 DEBUG : potato2: Deleting (id "4_z9fc25d43f07d1b6b7f280e1b_f104784f18cd00884_d20200515_m061551_c001_v0001120_t0033") 2020/05/15 06:25:09 DEBUG : potato2: Deleting (id "4_z9fc25d43f07d1b6b7f280e1b_f115f4d524660652d_d20200515_m061550_c001_v0001113_t0040") 2020/05/15 06:25:09 DEBUG : potato2: Deleting (id "4_z9fc25d43f07d1b6b7f280e1b_f101fceef9a863243_d20200515_m061545_c001_v0001136_t0056") 2020/05/15 06:25:09 DEBUG : potato2: Deleting (id "4_z9fc25d43f07d1b6b7f280e1b_f115f4d5246606521_d20200515_m061543_c001_v0001113_t0040") 2020/05/15 06:25:09 DEBUG : potato2: Deleting (id "4_z9fc25d43f07d1b6b7f280e1b_f1088ce6c1fb054b8_d20200515_m061517_c001_v0001134_t0014") 2020/05/15 06:25:09 DEBUG : potato2: Deleting (id "4_z9fc25d43f07d1b6b7f280e1b_f115f4d52466064e9_d20200515_m061514_c001_v0001113_t0040") 2020/05/15 06:25:09 DEBUG : potato2: Deleting (id "4_z9fc25d43f07d1b6b7f280e1b_f110d5f6bbfa22aeb_d20200515_m061358_c001_v0001134_t0055") 2020/05/15 06:25:09 DEBUG : potato2: Deleting (id "4_z9fc25d43f07d1b6b7f280e1b_f115f4d524660643e_d20200515_m061357_c001_v0001113_t0040") 2020/05/15 06:25:09 DEBUG : potato2: Deleting (id "4_z9fc25d43f07d1b6b7f280e1b_f111c120e75132376_d20200515_m061356_c001_v0001136_t0034") 2020/05/15 06:25:09 DEBUG : potato2: Deleting (id "4_z9fc25d43f07d1b6b7f280e1b_f115f4d5246606438_d20200515_m061353_c001_v0001113_t0040") 2020/05/15 06:25:09 DEBUG : potato3: Deleting (id "4_z9fc25d43f07d1b6b7f280e1b_f108c28cb9684e7ea_d20200515_m061929_c001_v0001091_t0008") 2020/05/15 06:25:09 DEBUG : potato3: Deleting (id "4_z9fc25d43f07d1b6b7f280e1b_f115f4d524660668b_d20200515_m061922_c001_v0001113_t0040") 2020/05/15 06:25:10 DEBUG : potato3: Deleting (id "4_z9fc25d43f07d1b6b7f280e1b_f11073aba2caaef99_d20200515_m061831_c001_v0001036_t0017") 2020/05/15 06:25:10 DEBUG : potato3: Deleting (id "4_z9fc25d43f07d1b6b7f280e1b_f115f4d524660662b_d20200515_m061827_c001_v0001113_t0040") 2020/05/15 06:25:10 DEBUG : potato3: Deleting (id "4_z9fc25d43f07d1b6b7f280e1b_f108addb697cbab56_d20200515_m061746_c001_v0001136_t0015") 2020/05/15 06:25:10 DEBUG : potato3: Deleting (id "4_z9fc25d43f07d1b6b7f280e1b_f115f4d52466065eb_d20200515_m061741_c001_v0001113_t0040") 2020/05/15 06:25:10 DEBUG : sizeonly: Deleting (id "4_z9fc25d43f07d1b6b7f280e1b_f109d36d209ff739d_d20200515_m061419_c001_v0001137_t0048") 2020/05/15 06:25:10 DEBUG : sizeonly: Deleting (id "4_z9fc25d43f07d1b6b7f280e1b_f115f4d524660646f_d20200515_m061418_c001_v0001113_t0040") 2020/05/15 06:25:10 DEBUG : sub dir/hello world: Deleting (id "4_z9fc25d43f07d1b6b7f280e1b_f1005d6a42904b0ca_d20200515_m061701_c001_v0001136_t0054") 2020/05/15 06:25:10 DEBUG : sub dir/hello world: Deleting (id "4_z9fc25d43f07d1b6b7f280e1b_f114295255b6d3853_d20200515_m061657_c001_v0001134_t0048") 2020/05/15 06:25:10 DEBUG : sub dir/hello world: Deleting (id "4_z9fc25d43f07d1b6b7f280e1b_f114295255b6d3848_d20200515_m061656_c001_v0001134_t0005") 2020/05/15 06:25:10 DEBUG : sub dir/hello world: Deleting (id "4_z9fc25d43f07d1b6b7f280e1b_f1129da768573349e_d20200515_m061655_c001_v0001036_t0037") 2020/05/15 06:25:10 DEBUG : sub dir/hello world: Deleting (id "4_z9fc25d43f07d1b6b7f280e1b_f106e7974c59868e9_d20200515_m061415_c001_v0001137_t0011") 2020/05/15 06:25:10 DEBUG : sub dir/hello world: Deleting (id "4_z9fc25d43f07d1b6b7f280e1b_f115f4d5246606468_d20200515_m061414_c001_v0001113_t0040") 2020/05/15 06:25:10 DEBUG : sub dir/hello world: Deleting (id "4_z9fc25d43f07d1b6b7f280e1b_f118581612d3b5ead_d20200515_m061413_c001_v0001130_t0054") 2020/05/15 06:25:10 DEBUG : sub dir/hello world: Deleting (id "4_z9fc25d43f07d1b6b7f280e1b_f115f4d5246606464_d20200515_m061412_c001_v0001113_t0040") 2020/05/15 06:25:10 DEBUG : sub dir/hello world: Deleting (id "4_z9fc25d43f07d1b6b7f280e1b_f10948238ab52e034_d20200515_m061410_c001_v0001134_t0027") 2020/05/15 06:25:10 DEBUG : sub dir/hello world: Deleting (id "4_z9fc25d43f07d1b6b7f280e1b_f115f4d5246606459_d20200515_m061405_c001_v0001113_t0040") 2020/05/15 06:25:10 DEBUG : sub dir/hello world: Deleting (id "4_z9fc25d43f07d1b6b7f280e1b_f109f30dad2877d21_d20200515_m061404_c001_v0001136_t0051") 2020/05/15 06:25:10 DEBUG : sub dir/hello world: Deleting (id "4_z9fc25d43f07d1b6b7f280e1b_f115f4d5246606453_d20200515_m061402_c001_v0001113_t0040") 2020/05/15 06:25:10 DEBUG : sub dir/hello world: Deleting (id "4_z9fc25d43f07d1b6b7f280e1b_f109f30dad2877cfa_d20200515_m061402_c001_v0001136_t0042") 2020/05/15 06:25:10 DEBUG : sub dir/hello world: Deleting (id "4_z9fc25d43f07d1b6b7f280e1b_f115f4d524660644d_d20200515_m061401_c001_v0001113_t0040") 2020/05/15 06:25:10 DEBUG : sub dir/hello world: Deleting (id "4_z9fc25d43f07d1b6b7f280e1b_f115235bdbb2e015e_d20200515_m061400_c001_v0001134_t0007") 2020/05/15 06:25:10 DEBUG : sub dir/hello world: Deleting (id "4_z9fc25d43f07d1b6b7f280e1b_f115f4d5246606447_d20200515_m061359_c001_v0001113_t0040") 2020/05/15 06:25:10 DEBUG : sub dir/hello world: Deleting (id "4_z9fc25d43f07d1b6b7f280e1b_f111215d2b369caa4_d20200515_m061352_c001_v0001013_t0043") 2020/05/15 06:25:10 DEBUG : sub dir/hello world: Deleting (id "4_z9fc25d43f07d1b6b7f280e1b_f115f4d5246606402_d20200515_m061333_c001_v0001113_t0040") 2020/05/15 06:25:10 DEBUG : sub dir/hello world: Deleting (id "4_z9fc25d43f07d1b6b7f280e1b_f102d1dc66f4f2e2b_d20200515_m061333_c001_v0001113_t0052") 2020/05/15 06:25:11 DEBUG : sub dir/hello world: Deleting (id "4_z9fc25d43f07d1b6b7f280e1b_f115a3c23d2e3fc9a_d20200515_m061332_c001_v0001137_t0038") 2020/05/15 06:25:11 DEBUG : sub dir/hello world: Deleting (id "4_z9fc25d43f07d1b6b7f280e1b_f115f4d52466063fe_d20200515_m061331_c001_v0001113_t0040") 2020/05/15 06:25:11 DEBUG : sub dir/hello world: Deleting (id "4_z9fc25d43f07d1b6b7f280e1b_f115b6c87c641eb23_d20200515_m061329_c001_v0001131_t0036") 2020/05/15 06:25:11 DEBUG : sub dir/hello world: Deleting (id "4_z9fc25d43f07d1b6b7f280e1b_f115f4d52466063f6_d20200515_m061328_c001_v0001113_t0040") 2020/05/15 06:25:11 DEBUG : three: Deleting (id "4_z9fc25d43f07d1b6b7f280e1b_f117c6c0235df64e5_d20200515_m061644_c001_v0001092_t0020") 2020/05/15 06:25:11 DEBUG : three: Deleting (id "4_z9fc25d43f07d1b6b7f280e1b_f115f4d5246606595_d20200515_m061642_c001_v0001113_t0040") 2020/05/15 06:25:11 DEBUG : three: Deleting (id "4_z9fc25d43f07d1b6b7f280e1b_f115f4d524660656d_d20200515_m061624_c001_v0001113_t0040") 2020/05/15 06:25:11 DEBUG : two: Deleting (id "4_z9fc25d43f07d1b6b7f280e1b_f1135a35305bda504_d20200515_m061644_c001_v0001113_t0037") 2020/05/15 06:25:11 DEBUG : two: Deleting (id "4_z9fc25d43f07d1b6b7f280e1b_f114295255b6d367b_d20200515_m061626_c001_v0001134_t0048") 2020/05/15 06:25:11 DEBUG : two: Deleting (id "4_z9fc25d43f07d1b6b7f280e1b_f115f4d5246606569_d20200515_m061624_c001_v0001113_t0040") 2020/05/15 06:25:11 DEBUG : yam: Deleting (id "4_z9fc25d43f07d1b6b7f280e1b_f1163c2127e3f18bc_d20200515_m061652_c001_v0001137_t0029") 2020/05/15 06:25:11 DEBUG : yam: Deleting (id "4_z9fc25d43f07d1b6b7f280e1b_f114295255b6d37ec_d20200515_m061650_c001_v0001134_t0048") 2020/05/15 06:25:11 DEBUG : yam: Deleting (id "4_z9fc25d43f07d1b6b7f280e1b_f1163c2127e3f1810_d20200515_m061647_c001_v0001137_t0011") 2020/05/15 06:25:11 DEBUG : yam: Deleting (id "4_z9fc25d43f07d1b6b7f280e1b_f114295255b6d37b9_d20200515_m061646_c001_v0001134_t0048") 2020/05/15 06:25:11 DEBUG : yaml: Deleting (id "4_z9fc25d43f07d1b6b7f280e1b_f1190ad2f91911f14_d20200515_m061653_c001_v0001113_t0040") 2020/05/15 06:25:11 DEBUG : yaml: Deleting (id "4_z9fc25d43f07d1b6b7f280e1b_f1137e31506bf8746_d20200515_m061652_c001_v0001137_t0048") 2020/05/15 06:25:11 DEBUG : yaml: Deleting (id "4_z9fc25d43f07d1b6b7f280e1b_f101a5b5fadecbbb0_d20200515_m061649_c001_v0001137_t0029") 2020/05/15 06:25:11 DEBUG : yaml: Deleting (id "4_z9fc25d43f07d1b6b7f280e1b_f113435d251c03184_d20200515_m061647_c001_v0001134_t0020") "./sync.test -test.v -test.timeout 1h0m0s -remote TestB2: -verbose -fast-list" - Finished ERROR in 11m46.566374968s (try 1/5): exit status 1: Failed [TestSyncNoTraverse TestCopyWithDepth TestSyncIgnoreTimes TestSyncAfterChangingModtimeOnly TestSyncAfterRemovingAFileAndAddingAFileSubDirWithErrors TestSyncDeleteDuring TestSyncSuffix]