"./sync.test -test.v -test.timeout 1h0m0s -remote TestB2: -verbose -test.run '^(TestMoveEmptyDirectories|TestServerSideCopy|TestSyncAfterChangingContentsOnly|TestSyncAfterChangingFilesSizeOnly|TestSyncDoesntUpdateModtime)$'" - Starting (try 2/5)
=== RUN   TestMoveEmptyDirectories
2020/05/15 05:30:43 DEBUG : sub dir2: Making directory
2020/05/15 05:30:44 DEBUG : B2 bucket rclone-test-lanupuk7garusal2tisamim9: Waiting for checks to finish
2020/05/15 05:30:44 DEBUG : B2 bucket rclone-test-lanupuk7garusal2tisamim9: Waiting for transfers to finish
2020/05/15 05:30:46 DEBUG : sub dir/hello world: SHA-1 = 2aae6c35c94fcfb415dbe95f408b9ce91ee846ed OK
2020/05/15 05:30:46 INFO  : sub dir/hello world: Copied (new)
2020/05/15 05:30:46 INFO  : sub dir/hello world: Deleted
2020/05/15 05:30:46 DEBUG : sub dir: Making directory
2020/05/15 05:30:46 DEBUG : sub dir2: Making directory
2020/05/15 05:30:46 DEBUG : B2 bucket rclone-test-lanupuk7garusal2tisamim9: copied 2 directories
--- PASS: TestMoveEmptyDirectories (3.16s)
    run.go:176: Remote "B2 bucket rclone-test-lanupuk7garusal2tisamim9", Local "Local file system at /tmp/rclone227313376", Modify Window "1ms"
    fstest.go:247: Filtering empty directory "sub dir2"
=== RUN   TestServerSideCopy
2020/05/15 05:30:48 DEBUG : B2 bucket rclone-test-kisujok7lujisis9repuhay6: Waiting for checks to finish
2020/05/15 05:30:48 DEBUG : B2 bucket rclone-test-kisujok7lujisis9repuhay6: Waiting for transfers to finish
2020/05/15 05:30:49 DEBUG : sub dir/hello world: SHA-1 = 2aae6c35c94fcfb415dbe95f408b9ce91ee846ed OK
2020/05/15 05:30:49 INFO  : sub dir/hello world: Copied (server side copy)
2020/05/15 05:30:49 DEBUG : B2 bucket rclone-test-kisujok7lujisis9repuhay6: Purge remote
2020/05/15 05:30:49 DEBUG : sub dir/hello world: Deleting (id "4_z1f924d93d00d1b6b7f280e1b_f101314c580890e3f_d20200515_m053048_c001_v0001128_t0050")
--- PASS: TestServerSideCopy (4.42s)
    run.go:176: Remote "B2 bucket rclone-test-lanupuk7garusal2tisamim9", Local "Local file system at /tmp/rclone227313376", Modify Window "1ms"
    sync_test.go:258: Server side copy (if possible) B2 bucket rclone-test-lanupuk7garusal2tisamim9 -> B2 bucket rclone-test-kisujok7lujisis9repuhay6
=== RUN   TestSyncDoesntUpdateModtime
2020/05/15 05:30:52 DEBUG : B2 bucket rclone-test-lanupuk7garusal2tisamim9: Waiting for checks to finish
2020/05/15 05:30: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 05:30:52 DEBUG : foo: SHA-1 = 0beec7b5ea3f0fdbc95d0dd47f3c5bc275da8a33 (Local file system at /tmp/rclone227313376)
2020/05/15 05:30:52 DEBUG : foo: SHA-1 = 62cdb7020ff920e5aa642c3d4066950dd1f01f4d (B2 bucket rclone-test-lanupuk7garusal2tisamim9)
2020/05/15 05:30:52 DEBUG : foo: SHA-1 differ
2020/05/15 05:30:52 DEBUG : B2 bucket rclone-test-lanupuk7garusal2tisamim9: Waiting for transfers to finish
2020/05/15 05:30:53 DEBUG : foo: SHA-1 = 0beec7b5ea3f0fdbc95d0dd47f3c5bc275da8a33 OK
2020/05/15 05:30:53 INFO  : foo: Copied (replaced existing)
2020/05/15 05:30:53 DEBUG : Waiting for deletions to finish
--- PASS: TestSyncDoesntUpdateModtime (3.40s)
    run.go:176: Remote "B2 bucket rclone-test-lanupuk7garusal2tisamim9", Local "Local file system at /tmp/rclone227313376", Modify Window "1ms"
=== RUN   TestSyncAfterChangingFilesSizeOnly
2020/05/15 05:30:55 DEBUG : B2 bucket rclone-test-lanupuk7garusal2tisamim9: Waiting for checks to finish
2020/05/15 05:30:55 DEBUG : potato: Sizes differ (src 21 vs dst 60)
2020/05/15 05:30:55 DEBUG : B2 bucket rclone-test-lanupuk7garusal2tisamim9: Waiting for transfers to finish
2020/05/15 05:30:56 DEBUG : potato: SHA-1 = 0fd321a1023ac4e1e1054fcc0236b9d0755f722f OK
2020/05/15 05:30:56 INFO  : potato: Copied (replaced existing)
2020/05/15 05:30:56 DEBUG : Waiting for deletions to finish
--- PASS: TestSyncAfterChangingFilesSizeOnly (2.40s)
    run.go:176: Remote "B2 bucket rclone-test-lanupuk7garusal2tisamim9", Local "Local file system at /tmp/rclone227313376", Modify Window "1ms"
=== RUN   TestSyncAfterChangingContentsOnly
2020/05/15 05:30:58 DEBUG : B2 bucket rclone-test-lanupuk7garusal2tisamim9: Waiting for checks to finish
2020/05/15 05:30:58 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 05:30:58 DEBUG : potato: SHA-1 = 1ca5094b3b73f587249eabe179c40a3eec839b1f (Local file system at /tmp/rclone227313376)
2020/05/15 05:30:58 DEBUG : potato: SHA-1 = 0fd321a1023ac4e1e1054fcc0236b9d0755f722f (B2 bucket rclone-test-lanupuk7garusal2tisamim9)
2020/05/15 05:30:58 DEBUG : potato: SHA-1 differ
2020/05/15 05:30:58 DEBUG : B2 bucket rclone-test-lanupuk7garusal2tisamim9: Waiting for transfers to finish
2020/05/15 05:30:58 DEBUG : potato: SHA-1 = 1ca5094b3b73f587249eabe179c40a3eec839b1f OK
2020/05/15 05:30:58 INFO  : potato: Copied (replaced existing)
2020/05/15 05:30:58 DEBUG : Waiting for deletions to finish
--- PASS: TestSyncAfterChangingContentsOnly (2.41s)
    run.go:176: Remote "B2 bucket rclone-test-lanupuk7garusal2tisamim9", Local "Local file system at /tmp/rclone227313376", Modify Window "1ms"
PASS
2020/05/15 05:30:59 DEBUG : B2 bucket rclone-test-lanupuk7garusal2tisamim9: Purge remote
2020/05/15 05:30:59 DEBUG : foo: Deleting (id "4_z8fc23d93d00d1b6b7f280e1b_f10888b12a85fe858_d20200515_m053053_c001_v0001137_t0035")
2020/05/15 05:30:59 DEBUG : foo: Deleting (id "4_z8fc23d93d00d1b6b7f280e1b_f117d99dd6d73a947_d20200515_m053052_c001_v0001137_t0002")
2020/05/15 05:30:59 DEBUG : foo: Deleting (id "4_z8fc23d93d00d1b6b7f280e1b_f117d99dd6d73a922_d20200515_m053051_c001_v0001137_t0002")
2020/05/15 05:30:59 DEBUG : potato: Deleting (id "4_z8fc23d93d00d1b6b7f280e1b_f10761dcb4e94d253_d20200515_m053059_c001_v0001134_t0042")
2020/05/15 05:30:59 DEBUG : potato: Deleting (id "4_z8fc23d93d00d1b6b7f280e1b_f117d99dd6d73aa15_d20200515_m053058_c001_v0001137_t0002")
2020/05/15 05:30:59 DEBUG : potato: Deleting (id "4_z8fc23d93d00d1b6b7f280e1b_f117d99dd6d73a9f5_d20200515_m053057_c001_v0001137_t0002")
2020/05/15 05:30:59 DEBUG : potato: Deleting (id "4_z8fc23d93d00d1b6b7f280e1b_f1006c2c426133273_d20200515_m053056_c001_v0001137_t0000")
2020/05/15 05:30:59 DEBUG : potato: Deleting (id "4_z8fc23d93d00d1b6b7f280e1b_f117d99dd6d73a9b8_d20200515_m053055_c001_v0001137_t0002")
2020/05/15 05:30:59 DEBUG : potato: Deleting (id "4_z8fc23d93d00d1b6b7f280e1b_f117d99dd6d73a994_d20200515_m053054_c001_v0001137_t0002")
2020/05/15 05:31:00 DEBUG : sub dir/hello world: Deleting (id "4_z8fc23d93d00d1b6b7f280e1b_f10888b12a85fe7cb_d20200515_m053050_c001_v0001137_t0017")
2020/05/15 05:31:00 DEBUG : sub dir/hello world: Deleting (id "4_z8fc23d93d00d1b6b7f280e1b_f117d99dd6d73a869_d20200515_m053047_c001_v0001137_t0002")
2020/05/15 05:31:00 DEBUG : sub dir/hello world: Deleting (id "4_z8fc23d93d00d1b6b7f280e1b_f110f80071640522d_d20200515_m053046_c001_v0001137_t0036")
2020/05/15 05:31:00 DEBUG : sub dir/hello world: Deleting (id "4_z8fc23d93d00d1b6b7f280e1b_f117d99dd6d73a82e_d20200515_m053045_c001_v0001137_t0002")
"./sync.test -test.v -test.timeout 1h0m0s -remote TestB2: -verbose -test.run '^(TestMoveEmptyDirectories|TestServerSideCopy|TestSyncAfterChangingContentsOnly|TestSyncAfterChangingFilesSizeOnly|TestSyncDoesntUpdateModtime)$'" - Finished OK in 17.820008851s (try 2/5)