def _add_block_flight_info(self, nodeid, height: int) -> None: request_info = self.block_requests.get(height, None) if request_info is None: # no outstanding requests for this particular height, so we create it req = convenience.RequestInfo(height) req.add_new_flight(convenience.FlightInfo(nodeid, height)) self.block_requests[height] = req else: request_info.flights.update( {nodeid: convenience.FlightInfo(nodeid, height)})
def test_on_block_received(self): # first test receiving a block we have no outstanding request for fake_block = asynctest.MagicMock() fake_block.index = 1 fake_block.__len__.return_value = 50 self.assertEqual( -1, self.syncmgr.on_block_received(from_nodeid=123, block=fake_block)) # next test receiving a block that we DO have an outstanding request for, but not from the node that is now # delivering the block request_info = convenience.RequestInfo(height=1) request_info.add_new_flight( convenience.FlightInfo(node_id=456, height=1)) self.syncmgr.block_requests[1] = request_info self.assertEqual( -2, self.syncmgr.on_block_received(from_nodeid=123, block=fake_block)) self.assertEqual(request_info, self.syncmgr.block_requests.get(1, None)) # next test a valid scenario (outstanding request and receiving a block from the right node) mocked_node = node.NeoNode(object()) mocked_node.nodeweight.append_new_speed = asynctest.MagicMock() mocked_node.nodeid = 456 self.nodemgr.nodes = [mocked_node] self.syncmgr.on_block_received(from_nodeid=456, block=fake_block) mocked_node.nodeweight.append_new_speed.assert_called_once() self.assertIn(fake_block, self.syncmgr.block_cache) self.assertEqual(1, len(self.syncmgr.block_cache)) # and finally try again for the same block and ensure it was not added again to the cache self.syncmgr.on_block_received(from_nodeid=456, block=fake_block) self.assertEqual(1, len(self.syncmgr.block_cache))
def test_most_recent_flight(self): ri = convenience.RequestInfo(0) self.assertIsNone(ri.most_recent_flight()) fi = convenience.FlightInfo(1, 0) ri.add_new_flight(fi) most_recent = ri.most_recent_flight() self.assertEqual(ri.last_used_node, fi.node_id)
async def test_no_flights_timedout(self): target_height = 1 request_info = convenience.RequestInfo(target_height) request_info.add_new_flight( convenience.FlightInfo(node_id=123, height=target_height)) self.syncmgr.block_requests[1] = request_info # a recently recreated flight should not have timed out self.assertEqual(-2, await self.syncmgr._check_timeout())
async def _check_timeout(self) -> int: """ This function checks if any of the outstanding data requests have exceeded the response time threshold. If so then the violating node is tagged. Next, a new node is selected to request the data we have not yet received in the hope that this node does perform adequately. """ if len(self.block_requests) == 0: # no outstanding data requests return -1 timedout_flights = dict() now = datetime.utcnow().timestamp() # find outstanding requests that timed out for height, request_info in self.block_requests.items(): flight_info = request_info.most_recent_flight() if flight_info and now - flight_info.start_time > self.BLOCK_REQUEST_TIMEOUT: timedout_flights[height] = flight_info if len(timedout_flights) == 0: # no timeouts, every request is still nicely within the threshold return -2 remaining_requests = [] nodes_to_tag_for_timeout = set() best_stored_block_height = self._get_best_stored_block_height() for height, flight_info in timedout_flights.items(): # adding to set to ensure we only tag nodes once per request nodes_to_tag_for_timeout.add(flight_info.node_id) try: request_info = self.block_requests[height] except KeyError: # TODO: check if still possible. After refactor should not be reachable anymore continue if flight_info.height <= best_stored_block_height: with suppress(KeyError): self.block_requests.pop(height) continue # tag the node for not delivering data within the set threshold request_info.mark_failed_node(flight_info.node_id) remaining_requests.append(request_info) for node_id in nodes_to_tag_for_timeout: # affect node weighting by increasing node timeout count self.nodemgr.increase_node_timeout_count(node_id) if len(remaining_requests) > 0: request_info_first = remaining_requests[0] request_info_last = remaining_requests[-1] # using the last request_info to find a suitable node, because the last request info is always the # highest block to look for node = self.nodemgr.get_least_failed_node(request_info_last) if node is None: # no connected nodes that can satisfy our request. # Return and let the node manager first resolve finding nodes return -3 # it is only possible to request block data by height (using the GetBlockData payload) for a consecutive # range. One option is to find these ranges and send a request for each range. Another option, which keeps # the code much simpler, is to just request the full range (from start to end height) and ignore any gaps # in the range that have been filled in the mean time by other nodes that timed out. # This leads to minimal (acceptable) additional traffic in certain scenarios. for request_info in remaining_requests: request_info.add_new_flight( convenience.FlightInfo(node.nodeid, request_info.height)) count = max(1, request_info_last.height - request_info_first.height) logger.debug( f"Block timeout for blocks {request_info_first.height} - {request_info_last.height}. " f"Trying again using next available node {node.nodeid_human}. " f"start={request_info_first.height}, count={count}.") await node.request_block_data( index_start=request_info_first.height, count=count) node.nodeweight.append_new_request_time() return 0
async def test_flights_timed_out(self): # scenario: have 2 outstanding flights that timed out # - 1 flight for a request that is still is not completed # - 1 flight has been made obsolete by a secondary for the same request_info and is still in cache waiting to be processed # construct flight 1 - request not yet satisfied target_height = 2 node1_id = 123 request_info = convenience.RequestInfo(target_height) request_info.mark_failed_node = asynctest.MagicMock() flight_info = convenience.FlightInfo(node_id=node1_id, height=target_height) # reduce start time to enforce exceeding timeout treshold flight_info.start_time -= self.syncmgr.BLOCK_REQUEST_TIMEOUT + 1 request_info.add_new_flight(flight_info) self.syncmgr.block_requests[target_height] = request_info # construct flight 2 - request already satisfied target_height2 = 1 node2_id = 456 request_info2 = convenience.RequestInfo(target_height2) flight_info2 = convenience.FlightInfo(node_id=node2_id, height=target_height2) flight_info2.start_time -= self.syncmgr.BLOCK_REQUEST_TIMEOUT + 1 request_info2.add_new_flight(flight_info2) self.syncmgr.block_requests[target_height2] = request_info2 # we patch '_get_best_stored_block_height' to return `target_height2` as a way of saying; # either the chain or cache already has the data for this height with asynctest.patch.object(self.syncmgr, '_get_best_stored_block_height', return_value=target_height2): with asynctest.patch.object(self.nodemgr, 'increase_node_timeout_count' ) as nodemgr_increase_timeout_count: result = await self.syncmgr._check_timeout() request_info.mark_failed_node.assert_called_with(node1_id) # both nodes had a flight that timed out nodemgr_increase_timeout_count.assert_has_calls( [asynctest.mock.call(node1_id), asynctest.mock.call(node2_id)], any_order=True) # the first time we call it we no longer have any connected nodes, so we can't request from anyone anymore self.assertEqual(-3, result) # now we "connect" a new node mock_node = node.NeoNode(protocol=object()) mock_node.best_height = 10 mock_node_id = 789 mock_node.nodeid = mock_node_id mock_node.request_block_data = asynctest.CoroutineMock() self.nodemgr.nodes = [mock_node] # and try again with self.assertLogs(network_logger, 'DEBUG') as log_context: with asynctest.patch.object(self.syncmgr, '_get_best_stored_block_height', return_value=target_height2): with asynctest.patch.object(self.nodemgr, 'increase_node_timeout_count'): await self.syncmgr._check_timeout() # and validate that a new data request is sent self.assertIn("Block timeout for blocks 2 - 2", log_context.output[0]) mock_node.request_block_data.assert_awaited_once_with(count=1, index_start=2) # and also a new flight was added for the new node flight = request_info.most_recent_flight() self.assertEqual(mock_node_id, flight.node_id) # just for coverage flight.reset_start_time() self.assertTrue( datetime.utcnow().timestamp() - flight.start_time < 0.1)