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)