"./sync.test -test.v -test.timeout 1h0m0s -remote TestOneDriveBusiness: -verbose -test.run '^TestSyncConcurrentTruncate$'" - Starting (try 5/5) 2021/12/01 05:36:28 DEBUG : Creating backend with remote "TestOneDriveBusiness:rclone-test-mayubuh7yimagam6wifebur3" 2021/12/01 05:36:28 DEBUG : Using config file from "/home/rclone/.rclone.conf" 2021/12/01 05:36:29 DEBUG : Creating backend with remote "/tmp/rclone1581478812" === RUN TestSyncConcurrentTruncate run.go:181: Remote "One drive root 'rclone-test-mayubuh7yimagam6wifebur3'", Local "Local file system at /tmp/rclone1581478812", Modify Window "1s" 2021/12/01 05:36:30 DEBUG : both0: Starting multipart upload 2021/12/01 05:36:30 DEBUG : both0: Uploading segment 0/6 size 6 2021/12/01 05:36:31 DEBUG : only0: Starting multipart upload 2021/12/01 05:36:32 DEBUG : only0: Uploading segment 0/6 size 6 2021/12/01 05:36:32 DEBUG : both1: Starting multipart upload 2021/12/01 05:36:34 DEBUG : both1: Uploading segment 0/6 size 6 2021/12/01 05:36:35 DEBUG : only1: Starting multipart upload 2021/12/01 05:36:35 DEBUG : only1: Uploading segment 0/6 size 6 2021/12/01 05:36:36 DEBUG : both2: Starting multipart upload 2021/12/01 05:36:37 DEBUG : both2: Uploading segment 0/6 size 6 2021/12/01 05:36:37 DEBUG : only2: Starting multipart upload 2021/12/01 05:36:38 DEBUG : only2: Uploading segment 0/6 size 6 2021/12/01 05:36:39 DEBUG : both3: Starting multipart upload 2021/12/01 05:36:39 DEBUG : both3: Uploading segment 0/6 size 6 2021/12/01 05:36:40 DEBUG : only3: Starting multipart upload 2021/12/01 05:36:41 DEBUG : only3: Uploading segment 0/6 size 6 2021/12/01 05:36:41 DEBUG : both4: Starting multipart upload 2021/12/01 05:36:42 DEBUG : both4: Uploading segment 0/6 size 6 2021/12/01 05:36:42 DEBUG : Too many requests. Trying again in 9 seconds. 2021/12/01 05:36:42 DEBUG : pacer: low level retry 1/10 (error activityLimitReached: throttledRequest: The request has been throttled) 2021/12/01 05:36:42 DEBUG : pacer: Rate limited, increasing sleep to 9s 2021/12/01 05:36:42 DEBUG : Too many requests. Trying again in 7 seconds. 2021/12/01 05:36:42 DEBUG : pacer: low level retry 2/10 (error activityLimitReached: throttledRequest: The request has been throttled) 2021/12/01 05:36:42 DEBUG : pacer: Rate limited, increasing sleep to 7s 2021/12/01 05:36:52 DEBUG : pacer: Reducing sleep to 5.25s 2021/12/01 05:36:52 DEBUG : only4: Starting multipart upload 2021/12/01 05:36:59 DEBUG : Too many requests. Trying again in 61 seconds. 2021/12/01 05:36:59 DEBUG : pacer: low level retry 1/10 (error activityLimitReached: throttledRequest: The request has been throttled) 2021/12/01 05:36:59 DEBUG : pacer: Rate limited, increasing sleep to 1m1s 2021/12/01 05:37:04 DEBUG : pacer: Reducing sleep to 45.75s 2021/12/01 05:37:04 DEBUG : only4: Uploading segment 0/6 size 6 2021/12/01 05:38:05 DEBUG : pacer: Reducing sleep to 34.3125s 2021/12/01 05:38:05 DEBUG : both5: Starting multipart upload 2021/12/01 05:38:51 DEBUG : pacer: Reducing sleep to 25.734375s 2021/12/01 05:38:51 DEBUG : both5: Uploading segment 0/6 size 6 2021/12/01 05:39:25 DEBUG : pacer: Reducing sleep to 19.30078125s 2021/12/01 05:39:25 DEBUG : only5: Starting multipart upload 2021/12/01 05:39:51 DEBUG : pacer: Reducing sleep to 14.475585937s 2021/12/01 05:39:51 DEBUG : only5: Uploading segment 0/6 size 6 2021/12/01 05:40:10 DEBUG : pacer: Reducing sleep to 10.856689452s 2021/12/01 05:40:10 DEBUG : both6: Starting multipart upload 2021/12/01 05:40:25 DEBUG : pacer: Reducing sleep to 8.142517089s 2021/12/01 05:40:25 DEBUG : both6: Uploading segment 0/6 size 6 2021/12/01 05:40:36 DEBUG : pacer: Reducing sleep to 6.106887816s 2021/12/01 05:40:36 DEBUG : only6: Starting multipart upload 2021/12/01 05:40:44 DEBUG : pacer: Reducing sleep to 4.580165862s 2021/12/01 05:40:44 DEBUG : only6: Uploading segment 0/6 size 6 2021/12/01 05:40:50 DEBUG : pacer: Reducing sleep to 3.435124396s 2021/12/01 05:40:50 DEBUG : both7: Starting multipart upload 2021/12/01 05:40:54 DEBUG : pacer: Reducing sleep to 2.576343297s 2021/12/01 05:40:54 DEBUG : both7: Uploading segment 0/6 size 6 2021/12/01 05:40:58 DEBUG : pacer: Reducing sleep to 1.932257472s 2021/12/01 05:40:58 DEBUG : only7: Starting multipart upload 2021/12/01 05:41:00 DEBUG : pacer: Reducing sleep to 1.449193104s 2021/12/01 05:41:00 DEBUG : only7: Uploading segment 0/6 size 6 2021/12/01 05:41:02 DEBUG : pacer: Reducing sleep to 1.086894828s 2021/12/01 05:41:02 DEBUG : both8: Starting multipart upload 2021/12/01 05:41:04 DEBUG : pacer: Reducing sleep to 815.171121ms 2021/12/01 05:41:04 DEBUG : both8: Uploading segment 0/6 size 6 2021/12/01 05:41:05 DEBUG : pacer: Reducing sleep to 611.37834ms 2021/12/01 05:41:05 DEBUG : only8: Starting multipart upload 2021/12/01 05:41:06 DEBUG : pacer: Reducing sleep to 458.533755ms 2021/12/01 05:41:06 DEBUG : only8: Uploading segment 0/6 size 6 2021/12/01 05:41:06 DEBUG : pacer: Reducing sleep to 343.900316ms 2021/12/01 05:41:06 DEBUG : both9: Starting multipart upload 2021/12/01 05:41:07 DEBUG : pacer: Reducing sleep to 257.925237ms 2021/12/01 05:41:07 DEBUG : both9: Uploading segment 0/6 size 6 2021/12/01 05:41:08 DEBUG : pacer: Reducing sleep to 193.443927ms 2021/12/01 05:41:08 DEBUG : only9: Starting multipart upload 2021/12/01 05:41:08 DEBUG : pacer: Reducing sleep to 145.082945ms 2021/12/01 05:41:08 DEBUG : only9: Uploading segment 0/6 size 6 2021/12/01 05:41:09 DEBUG : pacer: Reducing sleep to 108.812208ms 2021/12/01 05:41:09 DEBUG : both10: Starting multipart upload 2021/12/01 05:41:10 DEBUG : pacer: Reducing sleep to 81.609156ms 2021/12/01 05:41:10 DEBUG : both10: Uploading segment 0/6 size 6 2021/12/01 05:41:10 DEBUG : pacer: Reducing sleep to 61.206867ms 2021/12/01 05:41:10 DEBUG : only10: Starting multipart upload 2021/12/01 05:41:11 DEBUG : pacer: Reducing sleep to 45.90515ms 2021/12/01 05:41:11 DEBUG : only10: Uploading segment 0/6 size 6 2021/12/01 05:41:12 DEBUG : pacer: Reducing sleep to 34.428862ms 2021/12/01 05:41:12 DEBUG : both11: Starting multipart upload 2021/12/01 05:41:13 DEBUG : pacer: Reducing sleep to 25.821646ms 2021/12/01 05:41:13 DEBUG : both11: Uploading segment 0/6 size 6 2021/12/01 05:41:14 DEBUG : pacer: Reducing sleep to 19.366234ms 2021/12/01 05:41:14 DEBUG : only11: Starting multipart upload 2021/12/01 05:41:14 DEBUG : pacer: Reducing sleep to 14.524675ms 2021/12/01 05:41:14 DEBUG : only11: Uploading segment 0/6 size 6 2021/12/01 05:41:15 DEBUG : pacer: Reducing sleep to 10.893506ms 2021/12/01 05:41:15 DEBUG : both12: Starting multipart upload 2021/12/01 05:41:16 DEBUG : pacer: Reducing sleep to 10ms 2021/12/01 05:41:16 DEBUG : both12: Uploading segment 0/6 size 6 2021/12/01 05:41:16 DEBUG : only12: Starting multipart upload 2021/12/01 05:41:17 DEBUG : only12: Uploading segment 0/6 size 6 2021/12/01 05:41:18 DEBUG : both13: Starting multipart upload 2021/12/01 05:41:18 DEBUG : both13: Uploading segment 0/6 size 6 2021/12/01 05:41:19 DEBUG : only13: Starting multipart upload 2021/12/01 05:41:19 DEBUG : only13: Uploading segment 0/6 size 6 2021/12/01 05:41:20 DEBUG : both14: Starting multipart upload 2021/12/01 05:41:21 DEBUG : both14: Uploading segment 0/6 size 6 2021/12/01 05:41:21 DEBUG : only14: Starting multipart upload 2021/12/01 05:41:22 DEBUG : only14: Uploading segment 0/6 size 6 2021/12/01 05:41:23 DEBUG : both15: Starting multipart upload 2021/12/01 05:41:24 DEBUG : both15: Uploading segment 0/6 size 6 2021/12/01 05:41:24 DEBUG : only15: Starting multipart upload 2021/12/01 05:41:25 DEBUG : only15: Uploading segment 0/6 size 6 2021/12/01 05:41:26 DEBUG : both16: Starting multipart upload 2021/12/01 05:41:27 DEBUG : both16: Uploading segment 0/6 size 6 2021/12/01 05:41:27 DEBUG : only16: Starting multipart upload 2021/12/01 05:41:28 DEBUG : only16: Uploading segment 0/6 size 6 2021/12/01 05:41:29 DEBUG : both17: Starting multipart upload 2021/12/01 05:41:29 DEBUG : both17: Uploading segment 0/6 size 6 2021/12/01 05:41:30 DEBUG : only17: Starting multipart upload 2021/12/01 05:41:31 DEBUG : only17: Uploading segment 0/6 size 6 2021/12/01 05:41:32 DEBUG : both18: Starting multipart upload 2021/12/01 05:41:32 DEBUG : both18: Uploading segment 0/6 size 6 2021/12/01 05:41:33 DEBUG : only18: Starting multipart upload 2021/12/01 05:41:33 DEBUG : only18: Uploading segment 0/6 size 6 2021/12/01 05:41:34 DEBUG : both19: Starting multipart upload 2021/12/01 05:41:34 DEBUG : both19: Uploading segment 0/6 size 6 2021/12/01 05:41:35 DEBUG : only19: Starting multipart upload 2021/12/01 05:41:36 DEBUG : only19: Uploading segment 0/6 size 6 2021/12/01 05:41:37 DEBUG : both0: Size and modification time the same (differ by -499.999999ms, within tolerance 1s) 2021/12/01 05:41:37 DEBUG : both0: Unchanged skipping 2021/12/01 05:41:37 DEBUG : both11: Size and modification time the same (differ by -499.999999ms, within tolerance 1s) 2021/12/01 05:41:37 DEBUG : both11: Unchanged skipping 2021/12/01 05:41:37 DEBUG : both10: Size and modification time the same (differ by -499.999999ms, within tolerance 1s) 2021/12/01 05:41:37 DEBUG : both10: Unchanged skipping 2021/12/01 05:41:37 DEBUG : One drive root 'rclone-test-mayubuh7yimagam6wifebur3': Waiting for checks to finish 2021/12/01 05:41:37 DEBUG : both13: Size and modification time the same (differ by -499.999999ms, within tolerance 1s) 2021/12/01 05:41:37 DEBUG : both13: Unchanged skipping 2021/12/01 05:41:37 DEBUG : both14: Size and modification time the same (differ by -499.999999ms, within tolerance 1s) 2021/12/01 05:41:37 DEBUG : both14: Unchanged skipping 2021/12/01 05:41:37 DEBUG : both15: Size and modification time the same (differ by -499.999999ms, within tolerance 1s) 2021/12/01 05:41:37 DEBUG : both15: Unchanged skipping 2021/12/01 05:41:37 DEBUG : both16: Size and modification time the same (differ by -499.999999ms, within tolerance 1s) 2021/12/01 05:41:37 DEBUG : both16: Unchanged skipping 2021/12/01 05:41:37 DEBUG : both17: Size and modification time the same (differ by -499.999999ms, within tolerance 1s) 2021/12/01 05:41:37 DEBUG : both17: Unchanged skipping 2021/12/01 05:41:37 DEBUG : both18: Size and modification time the same (differ by -499.999999ms, within tolerance 1s) 2021/12/01 05:41:37 DEBUG : both18: Unchanged skipping 2021/12/01 05:41:37 DEBUG : both19: Size and modification time the same (differ by -499.999999ms, within tolerance 1s) 2021/12/01 05:41:37 DEBUG : both19: Unchanged skipping 2021/12/01 05:41:37 DEBUG : both2: Size and modification time the same (differ by -499.999999ms, within tolerance 1s) 2021/12/01 05:41:37 DEBUG : both2: Unchanged skipping 2021/12/01 05:41:37 DEBUG : both3: Size and modification time the same (differ by -499.999999ms, within tolerance 1s) 2021/12/01 05:41:37 DEBUG : both3: Unchanged skipping 2021/12/01 05:41:37 DEBUG : both4: Size and modification time the same (differ by -499.999999ms, within tolerance 1s) 2021/12/01 05:41:37 DEBUG : both4: Unchanged skipping 2021/12/01 05:41:37 DEBUG : both5: Size and modification time the same (differ by -499.999999ms, within tolerance 1s) 2021/12/01 05:41:37 DEBUG : both5: Unchanged skipping 2021/12/01 05:41:37 DEBUG : both6: Size and modification time the same (differ by -499.999999ms, within tolerance 1s) 2021/12/01 05:41:37 DEBUG : both6: Unchanged skipping 2021/12/01 05:41:37 DEBUG : both7: Size and modification time the same (differ by -499.999999ms, within tolerance 1s) 2021/12/01 05:41:37 DEBUG : both7: Unchanged skipping 2021/12/01 05:41:37 DEBUG : both8: Size and modification time the same (differ by -499.999999ms, within tolerance 1s) 2021/12/01 05:41:37 DEBUG : both8: Unchanged skipping 2021/12/01 05:41:37 DEBUG : both9: Size and modification time the same (differ by -499.999999ms, within tolerance 1s) 2021/12/01 05:41:37 DEBUG : both9: Unchanged skipping 2021/12/01 05:41:37 DEBUG : only0: Sizes differ (src 0 vs dst 6) 2021/12/01 05:41:37 DEBUG : only1: Sizes differ (src 0 vs dst 6) 2021/12/01 05:41:37 DEBUG : both12: Size and modification time the same (differ by -499.999999ms, within tolerance 1s) 2021/12/01 05:41:37 DEBUG : only10: Sizes differ (src 0 vs dst 6) 2021/12/01 05:41:37 DEBUG : both12: Unchanged skipping 2021/12/01 05:41:37 DEBUG : only11: Sizes differ (src 0 vs dst 6) 2021/12/01 05:41:37 DEBUG : only13: Sizes differ (src 0 vs dst 6) 2021/12/01 05:41:37 DEBUG : only12: Sizes differ (src 0 vs dst 6) 2021/12/01 05:41:37 DEBUG : only14: Sizes differ (src 0 vs dst 6) 2021/12/01 05:41:37 DEBUG : only15: Sizes differ (src 0 vs dst 6) 2021/12/01 05:41:37 DEBUG : only16: Sizes differ (src 0 vs dst 6) 2021/12/01 05:41:37 DEBUG : only17: Sizes differ (src 0 vs dst 6) 2021/12/01 05:41:37 DEBUG : only18: Sizes differ (src 0 vs dst 6) 2021/12/01 05:41:37 DEBUG : only19: Sizes differ (src 0 vs dst 6) 2021/12/01 05:41:37 DEBUG : both1: Size and modification time the same (differ by -499.999999ms, within tolerance 1s) 2021/12/01 05:41:37 DEBUG : both1: Unchanged skipping 2021/12/01 05:41:37 DEBUG : only2: Sizes differ (src 0 vs dst 6) 2021/12/01 05:41:37 DEBUG : only3: Sizes differ (src 0 vs dst 6) 2021/12/01 05:41:37 DEBUG : only4: Sizes differ (src 0 vs dst 6) 2021/12/01 05:41:37 DEBUG : only1: Starting singlepart upload 2021/12/01 05:41:37 DEBUG : only0: Starting singlepart upload 2021/12/01 05:41:37 DEBUG : only10: Starting singlepart upload 2021/12/01 05:41:37 DEBUG : only5: Sizes differ (src 0 vs dst 6) 2021/12/01 05:41:37 DEBUG : only6: Sizes differ (src 0 vs dst 6) 2021/12/01 05:41:37 DEBUG : only7: Sizes differ (src 0 vs dst 6) 2021/12/01 05:41:37 DEBUG : only8: Sizes differ (src 0 vs dst 6) 2021/12/01 05:41:37 DEBUG : only11: Starting singlepart upload 2021/12/01 05:41:37 DEBUG : only9: Sizes differ (src 0 vs dst 6) 2021/12/01 05:41:37 DEBUG : One drive root 'rclone-test-mayubuh7yimagam6wifebur3': Waiting for transfers to finish 2021/12/01 05:41:37 DEBUG : Too many requests. Trying again in 8 seconds. 2021/12/01 05:41:37 DEBUG : pacer: low level retry 1/10 (error activityLimitReached: throttledRequest: The request has been throttled) 2021/12/01 05:41:37 DEBUG : pacer: Rate limited, increasing sleep to 8s 2021/12/01 05:41:38 DEBUG : pacer: Reducing sleep to 6s 2021/12/01 05:41:38 DEBUG : pacer: Reducing sleep to 4.5s 2021/12/01 05:41:38 DEBUG : pacer: Reducing sleep to 3.375s 2021/12/01 05:41:38 DEBUG : pacer: Reducing sleep to 2.53125s 2021/12/01 05:41:46 DEBUG : pacer: Reducing sleep to 1.8984375s 2021/12/01 05:41:46 DEBUG : only1: quickxor = 0000000000000000000000000000000000000000 (Local file system at /tmp/rclone1581478812) 2021/12/01 05:41:46 DEBUG : only1: quickxor = 7078031dc2408737000000000600000000000000 (One drive root 'rclone-test-mayubuh7yimagam6wifebur3') 2021/12/01 05:41:46 ERROR : only1: corrupted on transfer: quickxor hash differ "0000000000000000000000000000000000000000" vs "7078031dc2408737000000000600000000000000" 2021/12/01 05:41:46 INFO : only1: Removing failed copy 2021/12/01 05:41:49 DEBUG : pacer: Reducing sleep to 1.423828125s 2021/12/01 05:41:49 DEBUG : only0: quickxor = 0000000000000000000000000000000000000000 (Local file system at /tmp/rclone1581478812) 2021/12/01 05:41:49 DEBUG : only0: quickxor = 7078031dc2408737000000000600000000000000 (One drive root 'rclone-test-mayubuh7yimagam6wifebur3') 2021/12/01 05:41:49 ERROR : only0: corrupted on transfer: quickxor hash differ "0000000000000000000000000000000000000000" vs "7078031dc2408737000000000600000000000000" 2021/12/01 05:41:49 INFO : only0: Removing failed copy 2021/12/01 05:41:51 DEBUG : pacer: Reducing sleep to 1.067871093s 2021/12/01 05:41:51 DEBUG : only10: quickxor = 0000000000000000000000000000000000000000 (Local file system at /tmp/rclone1581478812) 2021/12/01 05:41:51 DEBUG : only10: quickxor = 7078031dc2408737000000000600000000000000 (One drive root 'rclone-test-mayubuh7yimagam6wifebur3') 2021/12/01 05:41:51 ERROR : only10: corrupted on transfer: quickxor hash differ "0000000000000000000000000000000000000000" vs "7078031dc2408737000000000600000000000000" 2021/12/01 05:41:51 INFO : only10: Removing failed copy 2021/12/01 05:41:52 DEBUG : pacer: Reducing sleep to 800.903319ms 2021/12/01 05:41:52 DEBUG : only11: quickxor = 0000000000000000000000000000000000000000 (Local file system at /tmp/rclone1581478812) 2021/12/01 05:41:52 DEBUG : only11: quickxor = 7078031dc2408737000000000600000000000000 (One drive root 'rclone-test-mayubuh7yimagam6wifebur3') 2021/12/01 05:41:52 ERROR : only11: corrupted on transfer: quickxor hash differ "0000000000000000000000000000000000000000" vs "7078031dc2408737000000000600000000000000" 2021/12/01 05:41:52 INFO : only11: Removing failed copy 2021/12/01 05:41:53 DEBUG : pacer: Reducing sleep to 600.677489ms 2021/12/01 05:41:53 DEBUG : only13: Starting singlepart upload 2021/12/01 05:41:53 DEBUG : pacer: Reducing sleep to 450.508116ms 2021/12/01 05:41:53 DEBUG : only12: Starting singlepart upload 2021/12/01 05:41:54 DEBUG : pacer: Reducing sleep to 337.881087ms 2021/12/01 05:41:54 DEBUG : only14: Starting singlepart upload 2021/12/01 05:41:54 DEBUG : pacer: Reducing sleep to 253.410815ms 2021/12/01 05:41:54 DEBUG : only15: Starting singlepart upload 2021/12/01 05:41:55 DEBUG : pacer: Reducing sleep to 190.058111ms 2021/12/01 05:41:56 DEBUG : pacer: Reducing sleep to 142.543583ms 2021/12/01 05:41:56 DEBUG : Too many requests. Trying again in 61 seconds. 2021/12/01 05:41:56 DEBUG : pacer: low level retry 1/10 (error activityLimitReached: throttledRequest: The request has been throttled) 2021/12/01 05:41:56 DEBUG : pacer: Rate limited, increasing sleep to 1m1s 2021/12/01 05:41:56 DEBUG : pacer: Reducing sleep to 45.75s 2021/12/01 05:41:56 DEBUG : pacer: Reducing sleep to 34.3125s 2021/12/01 05:41:56 DEBUG : only14: quickxor = 0000000000000000000000000000000000000000 (Local file system at /tmp/rclone1581478812) 2021/12/01 05:41:56 DEBUG : only14: quickxor = 7078031dc2408737000000000600000000000000 (One drive root 'rclone-test-mayubuh7yimagam6wifebur3') 2021/12/01 05:41:56 ERROR : only14: corrupted on transfer: quickxor hash differ "0000000000000000000000000000000000000000" vs "7078031dc2408737000000000600000000000000" 2021/12/01 05:41:56 INFO : only14: Removing failed copy 2021/12/01 05:41:56 DEBUG : pacer: Reducing sleep to 25.734375s 2021/12/01 05:41:56 DEBUG : only13: quickxor = 0000000000000000000000000000000000000000 (Local file system at /tmp/rclone1581478812) 2021/12/01 05:41:56 DEBUG : only13: quickxor = 7078031dc2408737000000000600000000000000 (One drive root 'rclone-test-mayubuh7yimagam6wifebur3') 2021/12/01 05:41:56 ERROR : only13: corrupted on transfer: quickxor hash differ "0000000000000000000000000000000000000000" vs "7078031dc2408737000000000600000000000000" 2021/12/01 05:41:56 INFO : only13: Removing failed copy 2021/12/01 05:41:56 DEBUG : pacer: Reducing sleep to 19.30078125s 2021/12/01 05:42:42 DEBUG : pacer: Reducing sleep to 14.475585937s 2021/12/01 05:42:42 DEBUG : only15: quickxor = 0000000000000000000000000000000000000000 (Local file system at /tmp/rclone1581478812) 2021/12/01 05:42:42 DEBUG : only15: quickxor = 7078031dc2408737000000000600000000000000 (One drive root 'rclone-test-mayubuh7yimagam6wifebur3') 2021/12/01 05:42:42 ERROR : only15: corrupted on transfer: quickxor hash differ "0000000000000000000000000000000000000000" vs "7078031dc2408737000000000600000000000000" 2021/12/01 05:42:42 INFO : only15: Removing failed copy 2021/12/01 05:43:01 DEBUG : pacer: Reducing sleep to 10.856689452s 2021/12/01 05:43:01 DEBUG : only16: Starting singlepart upload 2021/12/01 05:43:16 DEBUG : pacer: Reducing sleep to 8.142517089s 2021/12/01 05:43:16 DEBUG : only17: Starting singlepart upload 2021/12/01 05:43:27 DEBUG : pacer: Reducing sleep to 6.106887816s 2021/12/01 05:43:27 DEBUG : only12: quickxor = 0000000000000000000000000000000000000000 (Local file system at /tmp/rclone1581478812) 2021/12/01 05:43:27 DEBUG : only12: quickxor = 7078031dc2408737000000000600000000000000 (One drive root 'rclone-test-mayubuh7yimagam6wifebur3') 2021/12/01 05:43:27 ERROR : only12: corrupted on transfer: quickxor hash differ "0000000000000000000000000000000000000000" vs "7078031dc2408737000000000600000000000000" 2021/12/01 05:43:27 INFO : only12: Removing failed copy 2021/12/01 05:43:35 DEBUG : pacer: Reducing sleep to 4.580165862s 2021/12/01 05:43:35 DEBUG : only18: Starting singlepart upload 2021/12/01 05:43:41 DEBUG : pacer: Reducing sleep to 3.435124396s 2021/12/01 05:43:46 DEBUG : pacer: Reducing sleep to 2.576343297s 2021/12/01 05:43:49 DEBUG : pacer: Reducing sleep to 1.932257472s 2021/12/01 05:43:49 DEBUG : only19: Starting singlepart upload 2021/12/01 05:43:51 DEBUG : Too many requests. Trying again in 49 seconds. 2021/12/01 05:43:51 DEBUG : pacer: low level retry 1/10 (error activityLimitReached: throttledRequest: The request has been throttled) 2021/12/01 05:43:51 DEBUG : pacer: Rate limited, increasing sleep to 49s 2021/12/01 05:43:53 DEBUG : pacer: Reducing sleep to 36.75s 2021/12/01 05:43:53 DEBUG : only16: quickxor = 0000000000000000000000000000000000000000 (Local file system at /tmp/rclone1581478812) 2021/12/01 05:43:53 DEBUG : only16: quickxor = 7078031dc2408737000000000600000000000000 (One drive root 'rclone-test-mayubuh7yimagam6wifebur3') 2021/12/01 05:43:53 ERROR : only16: corrupted on transfer: quickxor hash differ "0000000000000000000000000000000000000000" vs "7078031dc2408737000000000600000000000000" 2021/12/01 05:43:53 INFO : only16: Removing failed copy 2021/12/01 05:44:42 DEBUG : pacer: Reducing sleep to 27.5625s 2021/12/01 05:44:42 DEBUG : only17: quickxor = 0000000000000000000000000000000000000000 (Local file system at /tmp/rclone1581478812) 2021/12/01 05:44:42 DEBUG : only17: quickxor = 7078031dc2408737000000000600000000000000 (One drive root 'rclone-test-mayubuh7yimagam6wifebur3') 2021/12/01 05:44:42 ERROR : only17: corrupted on transfer: quickxor hash differ "0000000000000000000000000000000000000000" vs "7078031dc2408737000000000600000000000000" 2021/12/01 05:44:42 INFO : only17: Removing failed copy 2021/12/01 05:45:19 DEBUG : pacer: Reducing sleep to 20.671875s 2021/12/01 05:45:47 DEBUG : pacer: Reducing sleep to 15.50390625s 2021/12/01 05:46:07 DEBUG : pacer: Reducing sleep to 11.627929687s 2021/12/01 05:46:07 DEBUG : only2: Starting singlepart upload 2021/12/01 05:46:23 DEBUG : pacer: Reducing sleep to 8.720947265s 2021/12/01 05:46:23 DEBUG : only5: Starting singlepart upload 2021/12/01 05:46:34 DEBUG : pacer: Reducing sleep to 6.540710448s 2021/12/01 05:46:34 DEBUG : only19: quickxor = 0000000000000000000000000000000000000000 (Local file system at /tmp/rclone1581478812) 2021/12/01 05:46:34 DEBUG : only19: quickxor = 7078031dc2408737000000000600000000000000 (One drive root 'rclone-test-mayubuh7yimagam6wifebur3') 2021/12/01 05:46:34 ERROR : only19: corrupted on transfer: quickxor hash differ "0000000000000000000000000000000000000000" vs "7078031dc2408737000000000600000000000000" 2021/12/01 05:46:34 INFO : only19: Removing failed copy 2021/12/01 05:46:43 DEBUG : pacer: Reducing sleep to 4.905532836s 2021/12/01 05:46:43 DEBUG : only18: quickxor = 0000000000000000000000000000000000000000 (Local file system at /tmp/rclone1581478812) 2021/12/01 05:46:43 DEBUG : only18: quickxor = 7078031dc2408737000000000600000000000000 (One drive root 'rclone-test-mayubuh7yimagam6wifebur3') 2021/12/01 05:46:43 ERROR : only18: corrupted on transfer: quickxor hash differ "0000000000000000000000000000000000000000" vs "7078031dc2408737000000000600000000000000" 2021/12/01 05:46:43 INFO : only18: Removing failed copy 2021/12/01 05:46:50 DEBUG : pacer: Reducing sleep to 3.679149627s 2021/12/01 05:46:55 DEBUG : pacer: Reducing sleep to 2.75936222s 2021/12/01 05:46:58 DEBUG : pacer: Reducing sleep to 2.069521665s 2021/12/01 05:46:58 DEBUG : only6: Starting singlepart upload 2021/12/01 05:47:01 DEBUG : pacer: Reducing sleep to 1.552141248s 2021/12/01 05:47:01 DEBUG : only7: Starting singlepart upload 2021/12/01 05:47:03 DEBUG : pacer: Reducing sleep to 1.164105936s 2021/12/01 05:47:03 DEBUG : only2: quickxor = 0000000000000000000000000000000000000000 (Local file system at /tmp/rclone1581478812) 2021/12/01 05:47:03 DEBUG : only2: quickxor = 7078031dc2408737000000000600000000000000 (One drive root 'rclone-test-mayubuh7yimagam6wifebur3') 2021/12/01 05:47:03 ERROR : only2: corrupted on transfer: quickxor hash differ "0000000000000000000000000000000000000000" vs "7078031dc2408737000000000600000000000000" 2021/12/01 05:47:03 INFO : only2: Removing failed copy 2021/12/01 05:47:05 DEBUG : pacer: Reducing sleep to 873.079452ms 2021/12/01 05:47:05 DEBUG : only5: quickxor = 0000000000000000000000000000000000000000 (Local file system at /tmp/rclone1581478812) 2021/12/01 05:47:05 DEBUG : only5: quickxor = 7078031dc2408737000000000600000000000000 (One drive root 'rclone-test-mayubuh7yimagam6wifebur3') 2021/12/01 05:47:05 ERROR : only5: corrupted on transfer: quickxor hash differ "0000000000000000000000000000000000000000" vs "7078031dc2408737000000000600000000000000" 2021/12/01 05:47:05 INFO : only5: Removing failed copy 2021/12/01 05:47:06 DEBUG : pacer: Reducing sleep to 654.809589ms 2021/12/01 05:47:07 DEBUG : pacer: Reducing sleep to 491.107191ms 2021/12/01 05:47:07 DEBUG : pacer: Reducing sleep to 368.330393ms 2021/12/01 05:47:07 DEBUG : only8: Starting singlepart upload 2021/12/01 05:47:08 DEBUG : pacer: Reducing sleep to 276.247794ms 2021/12/01 05:47:08 DEBUG : only3: Starting singlepart upload 2021/12/01 05:47:08 DEBUG : pacer: Reducing sleep to 207.185845ms 2021/12/01 05:47:08 DEBUG : only6: quickxor = 0000000000000000000000000000000000000000 (Local file system at /tmp/rclone1581478812) 2021/12/01 05:47:08 DEBUG : only6: quickxor = 7078031dc2408737000000000600000000000000 (One drive root 'rclone-test-mayubuh7yimagam6wifebur3') 2021/12/01 05:47:08 ERROR : only6: corrupted on transfer: quickxor hash differ "0000000000000000000000000000000000000000" vs "7078031dc2408737000000000600000000000000" 2021/12/01 05:47:08 INFO : only6: Removing failed copy 2021/12/01 05:47:09 DEBUG : pacer: Reducing sleep to 155.389383ms 2021/12/01 05:47:09 DEBUG : only7: quickxor = 0000000000000000000000000000000000000000 (Local file system at /tmp/rclone1581478812) 2021/12/01 05:47:09 DEBUG : only7: quickxor = 7078031dc2408737000000000600000000000000 (One drive root 'rclone-test-mayubuh7yimagam6wifebur3') 2021/12/01 05:47:09 ERROR : only7: corrupted on transfer: quickxor hash differ "0000000000000000000000000000000000000000" vs "7078031dc2408737000000000600000000000000" 2021/12/01 05:47:09 INFO : only7: Removing failed copy 2021/12/01 05:47:09 DEBUG : pacer: Reducing sleep to 116.542037ms 2021/12/01 05:47:09 DEBUG : pacer: Reducing sleep to 87.406527ms 2021/12/01 05:47:09 DEBUG : only4: Starting singlepart upload 2021/12/01 05:47:09 DEBUG : pacer: Reducing sleep to 65.554895ms 2021/12/01 05:47:09 DEBUG : pacer: Reducing sleep to 49.166171ms 2021/12/01 05:47:09 DEBUG : only9: Starting singlepart upload 2021/12/01 05:47:10 DEBUG : pacer: Reducing sleep to 36.874628ms 2021/12/01 05:47:10 DEBUG : only8: quickxor = 0000000000000000000000000000000000000000 (Local file system at /tmp/rclone1581478812) 2021/12/01 05:47:10 DEBUG : only8: quickxor = 7078031dc2408737000000000600000000000000 (One drive root 'rclone-test-mayubuh7yimagam6wifebur3') 2021/12/01 05:47:10 ERROR : only8: corrupted on transfer: quickxor hash differ "0000000000000000000000000000000000000000" vs "7078031dc2408737000000000600000000000000" 2021/12/01 05:47:10 INFO : only8: Removing failed copy 2021/12/01 05:47:10 DEBUG : pacer: Reducing sleep to 27.655971ms 2021/12/01 05:47:10 DEBUG : pacer: Reducing sleep to 20.741978ms 2021/12/01 05:47:10 DEBUG : only3: quickxor = 0000000000000000000000000000000000000000 (Local file system at /tmp/rclone1581478812) 2021/12/01 05:47:10 DEBUG : only3: quickxor = 7078031dc2408737000000000600000000000000 (One drive root 'rclone-test-mayubuh7yimagam6wifebur3') 2021/12/01 05:47:10 ERROR : only3: corrupted on transfer: quickxor hash differ "0000000000000000000000000000000000000000" vs "7078031dc2408737000000000600000000000000" 2021/12/01 05:47:10 INFO : only3: Removing failed copy 2021/12/01 05:47:10 DEBUG : pacer: Reducing sleep to 15.556483ms 2021/12/01 05:47:10 DEBUG : pacer: Reducing sleep to 11.667362ms 2021/12/01 05:47:10 DEBUG : pacer: Reducing sleep to 10ms 2021/12/01 05:47:10 DEBUG : only9: quickxor = 0000000000000000000000000000000000000000 (Local file system at /tmp/rclone1581478812) 2021/12/01 05:47:10 DEBUG : only9: quickxor = 7078031dc2408737000000000600000000000000 (One drive root 'rclone-test-mayubuh7yimagam6wifebur3') 2021/12/01 05:47:10 ERROR : only9: corrupted on transfer: quickxor hash differ "0000000000000000000000000000000000000000" vs "7078031dc2408737000000000600000000000000" 2021/12/01 05:47:10 INFO : only9: Removing failed copy 2021/12/01 05:47:10 DEBUG : only4: quickxor = 0000000000000000000000000000000000000000 (Local file system at /tmp/rclone1581478812) 2021/12/01 05:47:10 DEBUG : only4: quickxor = 7078031dc2408737000000000600000000000000 (One drive root 'rclone-test-mayubuh7yimagam6wifebur3') 2021/12/01 05:47:10 ERROR : only4: corrupted on transfer: quickxor hash differ "0000000000000000000000000000000000000000" vs "7078031dc2408737000000000600000000000000" 2021/12/01 05:47:10 INFO : only4: Removing failed copy 2021/12/01 05:47:11 ERROR : One drive root 'rclone-test-mayubuh7yimagam6wifebur3': not deleting files as there were IO errors 2021/12/01 05:47:11 ERROR : One drive root 'rclone-test-mayubuh7yimagam6wifebur3': not deleting directories as there were IO errors sync_test.go:2056: Error Trace: sync_test.go:2056 sync_test.go:2066 Error: Received unexpected error: corrupted on transfer: quickxor hash differ "0000000000000000000000000000000000000000" vs "7078031dc2408737000000000600000000000000" Test: TestSyncConcurrentTruncate Messages: Sync must not return a error sync_test.go:2057: Error Trace: sync_test.go:2057 sync_test.go:2066 Error: Should be false Test: TestSyncConcurrentTruncate Messages: Low level errors must not have happened fstest.go:299: Sleeping for 1s for list eventual consistency: 1/3 fstest.go:302: Flushing the directory cache fstest.go:299: Sleeping for 2s for list eventual consistency: 2/3 fstest.go:302: Flushing the directory cache fstest.go:299: Sleeping for 4s for list eventual consistency: 3/3 fstest.go:302: Flushing the directory cache fstest.go:306: Error Trace: fstest.go:306 fstest.go:339 fstest.go:351 run.go:342 sync_test.go:2058 sync_test.go:2066 Error: Should be true Test: TestSyncConcurrentTruncate Messages: listing wrong, want both0 (6), both1 (6), both10 (6), both11 (6), both12 (6), both13 (6), both14 (6), both15 (6), both16 (6), both17 (6), both18 (6), both19 (6), both2 (6), both3 (6), both4 (6), both5 (6), both6 (6), both7 (6), both8 (6), both9 (6), only0 (0), only1 (0), only10 (0), only11 (0), only12 (0), only13 (0), only14 (0), only15 (0), only16 (0), only17 (0), only18 (0), only19 (0), only2 (0), only3 (0), only4 (0), only5 (0), only6 (0), only7 (0), only8 (0), only9 (0) got both0 (6), both1 (6), both10 (6), both11 (6), both12 (6), both13 (6), both14 (6), both15 (6), both16 (6), both17 (6), both18 (6), both19 (6), both2 (6), both3 (6), both4 (6), both5 (6), both6 (6), both7 (6), both8 (6), both9 (6) fstest.go:204: Not found "only18" fstest.go:204: Not found "only3" fstest.go:204: Not found "only14" fstest.go:204: Not found "only12" fstest.go:204: Not found "only4" fstest.go:204: Not found "only17" fstest.go:204: Not found "only8" fstest.go:204: Not found "only19" fstest.go:204: Not found "only1" fstest.go:204: Not found "only13" fstest.go:204: Not found "only2" fstest.go:204: Not found "only10" fstest.go:204: Not found "only7" fstest.go:204: Not found "only9" fstest.go:204: Not found "only11" fstest.go:204: Not found "only15" fstest.go:204: Not found "only0" fstest.go:204: Not found "only6" fstest.go:204: Not found "only5" fstest.go:204: Not found "only16" fstest.go:207: Error Trace: fstest.go:207 fstest.go:311 fstest.go:339 fstest.go:351 run.go:342 sync_test.go:2058 sync_test.go:2066 Error: Not equal: expected: 0 actual : 20 Test: TestSyncConcurrentTruncate Messages: 20 objects not found --- FAIL: TestSyncConcurrentTruncate (655.40s) FAIL 2021/12/01 05:47:24 DEBUG : One drive root 'rclone-test-mayubuh7yimagam6wifebur3': Purge remote "./sync.test -test.v -test.timeout 1h0m0s -remote TestOneDriveBusiness: -verbose -test.run '^TestSyncConcurrentTruncate$'" - Finished ERROR in 10m56.529535637s (try 5/5): exit status 1: Failed [TestSyncConcurrentTruncate]