"./sync.test -test.v -test.timeout 1h0m0s -remote TestB2: -verbose -fast-list -test.run '^(TestSyncAfterAddingAFile|TestSyncAfterChangingContentsOnly|TestSyncDoesntUpdateModtime)$'" - Starting (try 4/5)
=== RUN   TestSyncDoesntUpdateModtime
2020/07/24 10:01:54 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/07/24 10:01:54 DEBUG : B2 bucket rclone-test-tuzapaz9cobemuw4jumotab9: Waiting for checks to finish
2020/07/24 10:01:54 DEBUG : foo: SHA-1 = 0beec7b5ea3f0fdbc95d0dd47f3c5bc275da8a33 (Local file system at /tmp/rclone725837118)
2020/07/24 10:01:54 DEBUG : foo: SHA-1 = 62cdb7020ff920e5aa642c3d4066950dd1f01f4d (B2 bucket rclone-test-tuzapaz9cobemuw4jumotab9)
2020/07/24 10:01:54 DEBUG : foo: SHA-1 differ
2020/07/24 10:01:54 DEBUG : B2 bucket rclone-test-tuzapaz9cobemuw4jumotab9: Waiting for transfers to finish
2020/07/24 10:01:55 DEBUG : foo: SHA-1 = 0beec7b5ea3f0fdbc95d0dd47f3c5bc275da8a33 OK
2020/07/24 10:01:55 INFO  : foo: Copied (replaced existing)
2020/07/24 10:01:55 DEBUG : Waiting for deletions to finish
--- FAIL: TestSyncDoesntUpdateModtime (3.57s)
    run.go:176: Remote "B2 bucket rclone-test-tuzapaz9cobemuw4jumotab9", Local "Local file system at /tmp/rclone725837118", Modify Window "1ms"
    fstest.go:140: 
        	Error Trace:	fstest.go:140
        	            				fstest.go:146
        	            				fstest.go:192
        	            				fstest.go:305
        	            				fstest.go:335
        	            				fstest.go:347
        	            				sync_test.go:617
        	Error:      	Should be true
        	Test:       	TestSyncDoesntUpdateModtime
        	Messages:   	B2 bucket rclone-test-tuzapaz9cobemuw4jumotab9/foo: SHA-1 hash incorrect - expecting "0beec7b5ea3f0fdbc95d0dd47f3c5bc275da8a33" got "62cdb7020ff920e5aa642c3d4066950dd1f01f4d"
    fstest.go:124: 
        	Error Trace:	fstest.go:124
        	            				fstest.go:129
        	            				fstest.go:148
        	            				fstest.go:192
        	            				fstest.go:305
        	            				fstest.go:335
        	            				fstest.go:347
        	            				sync_test.go:617
        	Error:      	Should be true
        	Test:       	TestSyncDoesntUpdateModtime
        	Messages:   	foo: Modification time difference too big |95456h54m52.624456789s| > 1ms (want 2011-12-25 12:59:59.123456789 +0000 UTC vs got 2001-02-03 04:05:06.499 +0000 UTC) (precision 1ms)
=== RUN   TestSyncAfterAddingAFile
2020/07/24 10:01:56 DEBUG : empty space: Size and modification time the same (differ by -456.789µs, within tolerance 1ms)
2020/07/24 10:01:56 DEBUG : empty space: Unchanged skipping
2020/07/24 10:01:56 DEBUG : B2 bucket rclone-test-tuzapaz9cobemuw4jumotab9: Waiting for checks to finish
2020/07/24 10:01:56 DEBUG : B2 bucket rclone-test-tuzapaz9cobemuw4jumotab9: Waiting for transfers to finish
2020/07/24 10:01:56 DEBUG : potato: SHA-1 = 9dc7f7d3279715991a22853f5981df582b7f9f6d OK
2020/07/24 10:01:56 INFO  : potato: Copied (new)
2020/07/24 10:01:56 DEBUG : Waiting for deletions to finish
--- PASS: TestSyncAfterAddingAFile (3.39s)
    run.go:176: Remote "B2 bucket rclone-test-tuzapaz9cobemuw4jumotab9", Local "Local file system at /tmp/rclone725837118", Modify Window "1ms"
=== RUN   TestSyncAfterChangingContentsOnly
2020/07/24 10:02:00 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/07/24 10:02:00 DEBUG : B2 bucket rclone-test-tuzapaz9cobemuw4jumotab9: Waiting for checks to finish
2020/07/24 10:02:00 DEBUG : potato: SHA-1 = 1ca5094b3b73f587249eabe179c40a3eec839b1f (Local file system at /tmp/rclone725837118)
2020/07/24 10:02:00 DEBUG : potato: SHA-1 = 0fd321a1023ac4e1e1054fcc0236b9d0755f722f (B2 bucket rclone-test-tuzapaz9cobemuw4jumotab9)
2020/07/24 10:02:00 DEBUG : potato: SHA-1 differ
2020/07/24 10:02:00 DEBUG : B2 bucket rclone-test-tuzapaz9cobemuw4jumotab9: Waiting for transfers to finish
2020/07/24 10:02:00 DEBUG : potato: SHA-1 = 1ca5094b3b73f587249eabe179c40a3eec839b1f OK
2020/07/24 10:02:00 INFO  : potato: Copied (replaced existing)
2020/07/24 10:02:00 DEBUG : Waiting for deletions to finish
--- FAIL: TestSyncAfterChangingContentsOnly (9.16s)
    run.go:176: Remote "B2 bucket rclone-test-tuzapaz9cobemuw4jumotab9", Local "Local file system at /tmp/rclone725837118", 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:675
        	Error:      	Should be true
        	Test:       	TestSyncAfterChangingContentsOnly
        	Messages:   	listing wrong, want
        	            	   got
        	            	  potato (21)
    fstest.go:188: 
        	Error Trace:	fstest.go:188
        	            				fstest.go:305
        	            				fstest.go:335
        	            				run.go:169
        	            				run.go:339
        	            				sync_test.go:675
        	Error:      	Should be true
        	Test:       	TestSyncAfterChangingContentsOnly
        	Messages:   	Unexpected file "potato"
FAIL
2020/07/24 10:02:08 DEBUG : B2 bucket rclone-test-tuzapaz9cobemuw4jumotab9: Purge remote
2020/07/24 10:02:08 DEBUG : empty space: Deleting (id "4_zafb29de3405d8b0b7f380e1b_f100ba39cc2043a4c_d20200724_m100157_c001_v0001113_t0035")
2020/07/24 10:02:08 DEBUG : empty space: Deleting (id "4_zafb29de3405d8b0b7f380e1b_f10077d08f4443b9c_d20200724_m100156_c001_v0001093_t0031")
2020/07/24 10:02:08 DEBUG : foo: Deleting (id "4_zafb29de3405d8b0b7f380e1b_f11265c7df2a1d90e_d20200724_m100155_c001_v0001026_t0031")
2020/07/24 10:02:08 DEBUG : foo: Deleting (id "4_zafb29de3405d8b0b7f380e1b_f10077d08f4443b96_d20200724_m100154_c001_v0001093_t0031")
2020/07/24 10:02:08 DEBUG : foo: Deleting (id "4_zafb29de3405d8b0b7f380e1b_f10077d08f4443b98_d20200724_m100154_c001_v0001093_t0031")
2020/07/24 10:02:08 DEBUG : potato: Deleting (id "4_zafb29de3405d8b0b7f380e1b_f10077d08f4443bb0_d20200724_m100200_c001_v0001093_t0031")
2020/07/24 10:02:08 DEBUG : potato: Deleting (id "4_zafb29de3405d8b0b7f380e1b_f107181336e13581f_d20200724_m100200_c001_v0001137_t0005")
2020/07/24 10:02:08 DEBUG : potato: Deleting (id "4_zafb29de3405d8b0b7f380e1b_f10077d08f4443bac_d20200724_m100159_c001_v0001093_t0031")
2020/07/24 10:02:08 DEBUG : potato: Deleting (id "4_zafb29de3405d8b0b7f380e1b_f1193ec7ab22c4c07_d20200724_m100158_c001_v0001136_t0013")
2020/07/24 10:02:08 DEBUG : potato: Deleting (id "4_zafb29de3405d8b0b7f380e1b_f10077d08f4443b9e_d20200724_m100156_c001_v0001093_t0031")
"./sync.test -test.v -test.timeout 1h0m0s -remote TestB2: -verbose -fast-list -test.run '^(TestSyncAfterAddingAFile|TestSyncAfterChangingContentsOnly|TestSyncDoesntUpdateModtime)$'" - Finished ERROR in 18.304008006s (try 4/5): exit status 1: Failed [TestSyncDoesntUpdateModtime TestSyncAfterChangingContentsOnly]