"./sync.test -test.v -test.timeout 30m0s -remote TestB2: -verbose -test.run '^(TestSyncAfterChangingContentsOnly|TestSyncBackupDirWithSuffixKeepExtension|TestSyncEmptyDirectories|TestSyncSuffix)$'" - Starting (try 2/5)
=== RUN   TestSyncEmptyDirectories
2020/04/15 05:29:33 DEBUG : sub dir2: Making directory
2020/04/15 05:29:34 DEBUG : B2 bucket rclone-test-vuwavik7jupejuk7tuyeyif1: Waiting for checks to finish
2020/04/15 05:29:34 DEBUG : B2 bucket rclone-test-vuwavik7jupejuk7tuyeyif1: Waiting for transfers to finish
2020/04/15 05:29:36 DEBUG : sub dir/hello world: SHA-1 = 2aae6c35c94fcfb415dbe95f408b9ce91ee846ed OK
2020/04/15 05:29:36 INFO  : sub dir/hello world: Copied (new)
2020/04/15 05:29:36 DEBUG : sub dir2: Making directory
2020/04/15 05:29:36 DEBUG : B2 bucket rclone-test-vuwavik7jupejuk7tuyeyif1: copied 1 directories
2020/04/15 05:29:36 DEBUG : Waiting for deletions to finish
--- PASS: TestSyncEmptyDirectories (3.84s)
    run.go:176: Remote "B2 bucket rclone-test-vuwavik7jupejuk7tuyeyif1", Local "Local file system at /tmp/rclone220770670", Modify Window "1ms"
    fstest.go:241: Filtering empty directory "sub dir2"
=== RUN   TestSyncAfterChangingContentsOnly
2020/04/15 05:29:38 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/04/15 05:29:38 DEBUG : B2 bucket rclone-test-vuwavik7jupejuk7tuyeyif1: Waiting for checks to finish
2020/04/15 05:29:38 DEBUG : potato: SHA-1 = 1ca5094b3b73f587249eabe179c40a3eec839b1f (Local file system at /tmp/rclone220770670)
2020/04/15 05:29:38 DEBUG : potato: SHA-1 = 0fd321a1023ac4e1e1054fcc0236b9d0755f722f (B2 bucket rclone-test-vuwavik7jupejuk7tuyeyif1)
2020/04/15 05:29:38 DEBUG : potato: SHA-1 differ
2020/04/15 05:29:38 DEBUG : B2 bucket rclone-test-vuwavik7jupejuk7tuyeyif1: Waiting for transfers to finish
2020/04/15 05:29:38 DEBUG : potato: SHA-1 = 1ca5094b3b73f587249eabe179c40a3eec839b1f OK
2020/04/15 05:29:38 INFO  : potato: Copied (replaced existing)
2020/04/15 05:29:38 DEBUG : Waiting for deletions to finish
--- PASS: TestSyncAfterChangingContentsOnly (39.25s)
    run.go:176: Remote "B2 bucket rclone-test-vuwavik7jupejuk7tuyeyif1", Local "Local file system at /tmp/rclone220770670", Modify Window "1ms"
=== RUN   TestSyncBackupDirWithSuffixKeepExtension
2020/04/15 05:30:20 DEBUG : B2 bucket rclone-test-vuwavik7jupejuk7tuyeyif1 path dst: Waiting for checks to finish
2020/04/15 05:30:20 DEBUG : one: Sizes differ (src 4 vs dst 3)
2020/04/15 05:30:20 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2020/04/15 05:30:20 DEBUG : two: Unchanged skipping
2020/04/15 05:30:21 DEBUG : one: SHA-1 = fe05bcdcdc4928012781a5f1a2a77cbb5398e106 OK
2020/04/15 05:30:21 INFO  : one: Copied (server side copy)
2020/04/15 05:30:23 INFO  : one: Deleted
2020/04/15 05:30:23 DEBUG : B2 bucket rclone-test-vuwavik7jupejuk7tuyeyif1 path dst: Waiting for transfers to finish
2020/04/15 05:30:25 DEBUG : one: SHA-1 = d63a9910ed57f038b76549c070df6196b2102f42 OK
2020/04/15 05:30:25 INFO  : one: Copied (new)
2020/04/15 05:30:25 DEBUG : Waiting for deletions to finish
2020/04/15 05:30:26 DEBUG : three.txt: SHA-1 = b802f384302cb24fbab0a44997e820bf2e8507bb OK
2020/04/15 05:30:26 INFO  : three.txt: Copied (server side copy)
2020/04/15 05:30:26 INFO  : three.txt: Deleted
2020/04/15 05:30:26 INFO  : three.txt: Moved into backup dir
2020/04/15 05:30:27 DEBUG : B2 bucket rclone-test-vuwavik7jupejuk7tuyeyif1 path dst: Waiting for checks to finish
2020/04/15 05:30:27 DEBUG : one: Sizes differ (src 5 vs dst 4)
2020/04/15 05:30:27 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2020/04/15 05:30:27 DEBUG : two: Unchanged skipping
2020/04/15 05:30:28 DEBUG : one: SHA-1 = d63a9910ed57f038b76549c070df6196b2102f42 OK
2020/04/15 05:30:28 INFO  : one: Copied (server side copy)
2020/04/15 05:30:31 INFO  : one: Deleted
2020/04/15 05:30:31 DEBUG : B2 bucket rclone-test-vuwavik7jupejuk7tuyeyif1 path dst: Waiting for transfers to finish
2020/04/15 05:30:32 DEBUG : one: SHA-1 = 88a8c2880f555638f990d1ec4c8359b25caa20c7 OK
2020/04/15 05:30:32 INFO  : one: Copied (new)
2020/04/15 05:30:32 DEBUG : Waiting for deletions to finish
2020/04/15 05:30:34 DEBUG : three.txt: SHA-1 = 92e0258fe3c7456f15dff78d509f6e3c9166c254 OK
2020/04/15 05:30:34 INFO  : three.txt: Copied (server side copy)
2020/04/15 05:31:04 INFO  : three.txt: Deleted
2020/04/15 05:31:04 INFO  : three.txt: Moved into backup dir
--- PASS: TestSyncBackupDirWithSuffixKeepExtension (50.63s)
    run.go:176: Remote "B2 bucket rclone-test-vuwavik7jupejuk7tuyeyif1", Local "Local file system at /tmp/rclone220770670", Modify Window "1ms"
=== RUN   TestSyncSuffix
2020/04/15 05:31:10 DEBUG : one: Sizes differ (src 4 vs dst 3)
2020/04/15 05:31:10 DEBUG : one: SHA-1 = fe05bcdcdc4928012781a5f1a2a77cbb5398e106 OK
2020/04/15 05:31:10 INFO  : one: Copied (server side copy)
2020/04/15 05:31:13 INFO  : one: Deleted
2020/04/15 05:31:14 DEBUG : one: SHA-1 = d63a9910ed57f038b76549c070df6196b2102f42 OK
2020/04/15 05:31:14 INFO  : one: Copied (new)
2020/04/15 05:31:14 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2020/04/15 05:31:14 DEBUG : two: Unchanged skipping
2020/04/15 05:31:15 DEBUG : three.txt: Sizes differ (src 6 vs dst 5)
2020/04/15 05:31:15 DEBUG : three.txt: SHA-1 = b802f384302cb24fbab0a44997e820bf2e8507bb OK
2020/04/15 05:31:15 INFO  : three.txt: Copied (server side copy)
2020/04/15 05:31:17 INFO  : three.txt: Deleted
2020/04/15 05:31:18 DEBUG : three.txt: SHA-1 = 92e0258fe3c7456f15dff78d509f6e3c9166c254 OK
2020/04/15 05:31:18 INFO  : three.txt: Copied (new)
2020/04/15 05:31:18 DEBUG : one: Sizes differ (src 5 vs dst 4)
2020/04/15 05:31:19 DEBUG : one: SHA-1 = d63a9910ed57f038b76549c070df6196b2102f42 OK
2020/04/15 05:31:19 INFO  : one: Copied (server side copy)
2020/04/15 05:31:20 INFO  : one: Deleted
2020/04/15 05:31:24 DEBUG : one: SHA-1 = 88a8c2880f555638f990d1ec4c8359b25caa20c7 OK
2020/04/15 05:31:24 INFO  : one: Copied (new)
2020/04/15 05:31:24 DEBUG : two: Size and modification time the same (differ by -999.999µs, within tolerance 1ms)
2020/04/15 05:31:24 DEBUG : two: Unchanged skipping
2020/04/15 05:31:24 DEBUG : three.txt: Sizes differ (src 19 vs dst 6)
2020/04/15 05:31:26 DEBUG : three.txt: SHA-1 = 92e0258fe3c7456f15dff78d509f6e3c9166c254 OK
2020/04/15 05:31:26 INFO  : three.txt: Copied (server side copy)
2020/04/15 05:31:27 INFO  : three.txt: Deleted
2020/04/15 05:31:31 DEBUG : three.txt: SHA-1 = 476e1707cbd7f0497a7dc4d44f0b07b8566ffc30 OK
2020/04/15 05:31:31 INFO  : three.txt: Copied (new)
--- PASS: TestSyncSuffix (26.80s)
    run.go:176: Remote "B2 bucket rclone-test-vuwavik7jupejuk7tuyeyif1", Local "Local file system at /tmp/rclone220770670", Modify Window "1ms"
PASS
2020/04/15 05:31:34 DEBUG : B2 bucket rclone-test-vuwavik7jupejuk7tuyeyif1: Purge remote
2020/04/15 05:31:34 DEBUG : backup/one-2019-01-01: Deleting (id "4_z2fc26d03500d7bcb7f180e1b_f118fcf16a9e314e8_d20200415_m053105_c001_v0001134_t0039")
2020/04/15 05:31:34 DEBUG : backup/one-2019-01-01: Deleting (id "4_z2fc26d03500d7bcb7f180e1b_f118fb2b643d1f60c_d20200415_m053028_c001_v0001013_t0014")
2020/04/15 05:31:34 DEBUG : backup/one-2019-01-01: Deleting (id "4_z2fc26d03500d7bcb7f180e1b_f1163808166d9ae6a_d20200415_m053020_c001_v0001136_t0009")
2020/04/15 05:31:34 DEBUG : backup/three-2019-01-01.txt: Deleting (id "4_z2fc26d03500d7bcb7f180e1b_f1151ecb206773ffe_d20200415_m053106_c001_v0001136_t0056")
2020/04/15 05:31:34 DEBUG : backup/three-2019-01-01.txt: Deleting (id "4_z2fc26d03500d7bcb7f180e1b_f112358dec4b69183_d20200415_m053032_c001_v0001038_t0045")
2020/04/15 05:31:34 DEBUG : backup/three-2019-01-01.txt: Deleting (id "4_z2fc26d03500d7bcb7f180e1b_f1089099dc89ea738_d20200415_m053026_c001_v0001090_t0001")
2020/04/15 05:31:34 DEBUG : dst/one: Deleting (id "4_z2fc26d03500d7bcb7f180e1b_f113b998a6f28d4a8_d20200415_m053131_c001_v0001009_t0024")
2020/04/15 05:31:34 DEBUG : dst/one: Deleting (id "4_z2fc26d03500d7bcb7f180e1b_f1021d606045581fa_d20200415_m053120_c001_v0001093_t0032")
2020/04/15 05:31:34 DEBUG : dst/one: Deleting (id "4_z2fc26d03500d7bcb7f180e1b_f111847154c7290ce_d20200415_m053119_c001_v0001113_t0053")
2020/04/15 05:31:34 DEBUG : dst/one: Deleting (id "4_z2fc26d03500d7bcb7f180e1b_f1021d606045581e9_d20200415_m053114_c001_v0001093_t0032")
2020/04/15 05:31:34 DEBUG : dst/one: Deleting (id "4_z2fc26d03500d7bcb7f180e1b_f104555f1bf7f8a14_d20200415_m053111_c001_v0001013_t0028")
2020/04/15 05:31:35 DEBUG : dst/one: Deleting (id "4_z2fc26d03500d7bcb7f180e1b_f114360bfdebd2c02_d20200415_m053108_c001_v0001128_t0012")
2020/04/15 05:31:35 DEBUG : dst/one: Deleting (id "4_z2fc26d03500d7bcb7f180e1b_f1071db96eecd1580_d20200415_m053106_c001_v0001031_t0033")
2020/04/15 05:31:35 DEBUG : dst/one: Deleting (id "4_z2fc26d03500d7bcb7f180e1b_f10667ae056445f04_d20200415_m053031_c001_v0001033_t0047")
2020/04/15 05:31:35 DEBUG : dst/one: Deleting (id "4_z2fc26d03500d7bcb7f180e1b_f1021d606045581b6_d20200415_m053028_c001_v0001093_t0048")
2020/04/15 05:31:35 DEBUG : dst/one: Deleting (id "4_z2fc26d03500d7bcb7f180e1b_f10667ae056445f01_d20200415_m053024_c001_v0001033_t0047")
2020/04/15 05:31:35 DEBUG : dst/one: Deleting (id "4_z2fc26d03500d7bcb7f180e1b_f10688eb82009f7b3_d20200415_m053021_c001_v0001134_t0058")
2020/04/15 05:31:35 DEBUG : dst/one: Deleting (id "4_z2fc26d03500d7bcb7f180e1b_f114360bfdebd2b85_d20200415_m053017_c001_v0001128_t0012")
2020/04/15 05:31:35 DEBUG : dst/one.bak: Deleting (id "4_z2fc26d03500d7bcb7f180e1b_f107d8436b7dd00bf_d20200415_m053132_c001_v0001038_t0014")
2020/04/15 05:31:35 DEBUG : dst/one.bak: Deleting (id "4_z2fc26d03500d7bcb7f180e1b_f11873d4a9abc2168_d20200415_m053118_c001_v0001022_t0005")
2020/04/15 05:31:35 DEBUG : dst/one.bak: Deleting (id "4_z2fc26d03500d7bcb7f180e1b_f1131f43848bff450_d20200415_m053110_c001_v0001044_t0035")
2020/04/15 05:31:35 DEBUG : dst/three.txt: Deleting (id "4_z2fc26d03500d7bcb7f180e1b_f1035e9f20005bd09_d20200415_m053132_c001_v0001136_t0001")
2020/04/15 05:31:35 DEBUG : dst/three.txt: Deleting (id "4_z2fc26d03500d7bcb7f180e1b_f1021d60604558204_d20200415_m053127_c001_v0001093_t0032")
2020/04/15 05:31:35 DEBUG : dst/three.txt: Deleting (id "4_z2fc26d03500d7bcb7f180e1b_f103661b0efda0869_d20200415_m053126_c001_v0001041_t0025")
2020/04/15 05:31:35 DEBUG : dst/three.txt: Deleting (id "4_z2fc26d03500d7bcb7f180e1b_f1021d606045581ef_d20200415_m053117_c001_v0001093_t0032")
2020/04/15 05:31:35 DEBUG : dst/three.txt: Deleting (id "4_z2fc26d03500d7bcb7f180e1b_f118d7be88d4f4677_d20200415_m053116_c001_v0001033_t0022")
2020/04/15 05:31:35 DEBUG : dst/three.txt: Deleting (id "4_z2fc26d03500d7bcb7f180e1b_f114360bfdebd2c06_d20200415_m053108_c001_v0001128_t0012")
2020/04/15 05:31:35 DEBUG : dst/three.txt: Deleting (id "4_z2fc26d03500d7bcb7f180e1b_f1085df636ca5a304_d20200415_m053104_c001_v0001134_t0028")
2020/04/15 05:31:35 DEBUG : dst/three.txt: Deleting (id "4_z2fc26d03500d7bcb7f180e1b_f114360bfdebd2ba0_d20200415_m053027_c001_v0001128_t0012")
2020/04/15 05:31:35 DEBUG : dst/three.txt: Deleting (id "4_z2fc26d03500d7bcb7f180e1b_f108e5bdb3df75215_d20200415_m053026_c001_v0001131_t0039")
2020/04/15 05:31:35 DEBUG : dst/three.txt: Deleting (id "4_z2fc26d03500d7bcb7f180e1b_f114360bfdebd2b88_d20200415_m053018_c001_v0001128_t0012")
2020/04/15 05:31:35 DEBUG : dst/three.txt.bak: Deleting (id "4_z2fc26d03500d7bcb7f180e1b_f107ab4a9fdd46d4d_d20200415_m053133_c001_v0001005_t0018")
2020/04/15 05:31:36 DEBUG : dst/three.txt.bak: Deleting (id "4_z2fc26d03500d7bcb7f180e1b_f1078d3bb93529a51_d20200415_m053124_c001_v0001136_t0015")
2020/04/15 05:31:36 DEBUG : dst/three.txt.bak: Deleting (id "4_z2fc26d03500d7bcb7f180e1b_f1151ecb206774064_d20200415_m053115_c001_v0001136_t0043")
2020/04/15 05:31:36 DEBUG : dst/two: Deleting (id "4_z2fc26d03500d7bcb7f180e1b_f119b15e332b2bba5_d20200415_m053134_c001_v0001134_t0001")
2020/04/15 05:31:36 DEBUG : dst/two: Deleting (id "4_z2fc26d03500d7bcb7f180e1b_f114360bfdebd2c04_d20200415_m053108_c001_v0001128_t0012")
2020/04/15 05:31:36 DEBUG : dst/two: Deleting (id "4_z2fc26d03500d7bcb7f180e1b_f1135452926d7c44e_d20200415_m053107_c001_v0001128_t0013")
2020/04/15 05:31:36 DEBUG : dst/two: Deleting (id "4_z2fc26d03500d7bcb7f180e1b_f114360bfdebd2b87_d20200415_m053017_c001_v0001128_t0012")
2020/04/15 05:31:36 DEBUG : potato: Deleting (id "4_z2fc26d03500d7bcb7f180e1b_f100f648429e882a4_d20200415_m053009_c001_v0001029_t0009")
2020/04/15 05:31:36 DEBUG : potato: Deleting (id "4_z2fc26d03500d7bcb7f180e1b_f114360bfdebd2b23_d20200415_m052938_c001_v0001128_t0012")
2020/04/15 05:31:36 DEBUG : potato: Deleting (id "4_z2fc26d03500d7bcb7f180e1b_f114360bfdebd2b1f_d20200415_m052937_c001_v0001128_t0012")
2020/04/15 05:31:36 DEBUG : sub dir/hello world: Deleting (id "4_z2fc26d03500d7bcb7f180e1b_f10199391eac6f873_d20200415_m052936_c001_v0001091_t0059")
2020/04/15 05:31:36 DEBUG : sub dir/hello world: Deleting (id "4_z2fc26d03500d7bcb7f180e1b_f114360bfdebd2b16_d20200415_m052935_c001_v0001128_t0012")
"./sync.test -test.v -test.timeout 30m0s -remote TestB2: -verbose -test.run '^(TestSyncAfterChangingContentsOnly|TestSyncBackupDirWithSuffixKeepExtension|TestSyncEmptyDirectories|TestSyncSuffix)$'" - Finished OK in 2m4.13973374s (try 2/5)