def __init__(self,
chain: AsyncChainAPI,
db: BaseAsyncChainDB,
peer_pool: ETHPeerPool,
header_syncer: HeaderSyncerAPI,
block_importer: BaseBlockImporter,
token: CancelToken = None) -> None:
super().__init__(chain, db, peer_pool, header_syncer, token)
# track when block bodies are downloaded, so that blocks can be imported
self._block_import_tracker = OrderedTaskPreparation(
BlockImportPrereqs,
id_extractor=attrgetter('hash'),
# make sure that a block is not imported until the parent block is imported
dependency_extractor=attrgetter('parent_hash'),
# Avoid problems by keeping twice as much data as the import queue size
max_depth=BLOCK_IMPORT_QUEUE_SIZE * 2,
)
self._block_importer = block_importer
# Track if any headers have been received yet
self._got_first_header = asyncio.Event()
# Rate limit the block import logs
self._import_log_limiter = TokenBucket(
0.33, # show about one log per 3 seconds
5, # burst up to 5 logs after a lag
)
# the queue of blocks that are downloaded and ready to be imported
self._import_queue: 'asyncio.Queue[BlockAPI]' = asyncio.Queue(BLOCK_IMPORT_QUEUE_SIZE)
self._import_active = asyncio.Lock()
def __init__(self,
chain: BaseAsyncChain,
db: BaseAsyncChainDB,
peer_pool: ETHPeerPool,
header_syncer: HeaderSyncerAPI,
block_importer: BaseBlockImporter,
token: CancelToken = None) -> None:
super().__init__(chain, db, peer_pool, header_syncer, token)
# track when block bodies are downloaded, so that blocks can be imported
self._block_import_tracker = OrderedTaskPreparation(
BlockImportPrereqs,
id_extractor=attrgetter('hash'),
# make sure that a block is not imported until the parent block is imported
dependency_extractor=attrgetter('parent_hash'),
)
self._block_importer = block_importer
# Track if any headers have been received yet
self._got_first_header = asyncio.Event()
# Rate limit the block import logs
self._import_log_limiter = TokenBucket(
0.33, # show about one log per 3 seconds
5, # burst up to 5 logs after a lag
)
async def maybe_connect_more_peers(self) -> None:
rate_limiter = TokenBucket(
rate=1 / PEER_CONNECT_INTERVAL,
capacity=MAX_SEQUENTIAL_PEER_CONNECT,
)
while self.is_operational:
if self.is_full:
await self.sleep(PEER_CONNECT_INTERVAL)
continue
await self.wait(rate_limiter.take())
try:
await asyncio.gather(*(self._add_peers_from_backend(backend)
for backend in self.peer_backends))
except OperationCancelled:
break
except asyncio.CancelledError:
# no need to log this exception, this is expected
raise
except Exception:
self.logger.exception(
"unexpected error during peer connection")
# Continue trying to connect to peers, even if there was a
# surprising failure during one of the attempts.
continue
def __init__(self, peer: BasePeer, response_msg_type: Type[CommandAPI],
token: CancelToken) -> None:
super().__init__(token)
self._peer = peer
self.response_msg_type = response_msg_type
self._lock = asyncio.Lock()
# token bucket for limiting timeouts.
# - Refills at 1-token every 5 minutes
# - Max capacity of 3 tokens
self.timeout_bucket = TokenBucket(TIMEOUT_BUCKET_RATE,
TIMEOUT_BUCKET_CAPACITY)
def __init__(self, peer: BasePeer, listening_for: Type[CommandAPI],
cancel_token: CancelToken) -> None:
self._peer = peer
self._cancel_token = cancel_token
self._response_command_type = listening_for
# This TokenBucket allows for the occasional invalid response at a
# maximum rate of 1-per-10-minutes and allowing up to two in quick
# succession. We *allow* invalid responses because the ETH protocol
# doesn't have strong correlation between request/response and certain
# networking conditions can result in us interpreting a legitimate
# message as an invalid response if messages arrive out of order or
# late.
self._invalid_response_bucket = TokenBucket(1 / 600, 2)
async def maybe_connect_more_peers(self) -> None:
rate_limiter = TokenBucket(
rate=1 / PEER_CONNECT_INTERVAL,
capacity=MAX_SEQUENTIAL_PEER_CONNECT,
)
# We set this to 0 so that upon startup (when our RoutingTable will have only a few
# entries) we use the less restrictive filter function and get as many connection
# candidates as possible.
last_candidates_count = 0
while self.is_operational:
if self.is_full:
await self.sleep(PEER_CONNECT_INTERVAL)
continue
await self.wait(rate_limiter.take())
if last_candidates_count >= self.available_slots:
head = await self.get_chain_head()
genesis_hash = await self.get_genesis_hash()
fork_blocks = extract_fork_blocks(self.vm_configuration)
should_skip = functools.partial(
skip_candidate_if_on_list_or_fork_mismatch,
genesis_hash,
head.block_number,
fork_blocks,
)
else:
self.logger.debug(
"Didn't get enough candidates last time, falling back to skipping "
"only peers that are blacklisted or already connected to")
should_skip = skip_candidate_if_on_list # type: ignore
try:
candidate_counts = await asyncio.gather(
*(self._add_peers_from_backend(backend, should_skip)
for backend in self.peer_backends))
last_candidates_count = sum(candidate_counts)
except OperationCancelled:
break
except asyncio.CancelledError:
# no need to log this exception, this is expected
raise
except Exception:
self.logger.exception(
"unexpected error during peer connection")
# Continue trying to connect to peers, even if there was a
# surprising failure during one of the attempts.
continue
async def maybe_connect_more_peers(self) -> None:
rate_limiter = TokenBucket(
rate=1 / PEER_CONNECT_INTERVAL,
capacity=MAX_SEQUENTIAL_PEER_CONNECT,
)
while self.is_operational:
if self.is_full:
await self.sleep(PEER_CONNECT_INTERVAL)
continue
await self.wait(rate_limiter.take())
await self.wait(
asyncio.gather(*(self._add_peers_from_backend(backend)
for backend in self.peer_backends)))
async def measure_zero(iterations):
bucket = TokenBucket(1, iterations)
start_at = time.perf_counter()
for _ in range(iterations):
await bucket.take()
end_at = time.perf_counter()
return end_at - start_at
async def test_token_bucket_refills_itself():
CAPACITY = 50
TOKENS_PER_SECOND = 1000
bucket = TokenBucket(TOKENS_PER_SECOND, CAPACITY)
# consume all of the tokens
for _ in range(CAPACITY):
await bucket.take()
# enough time for the bucket to fully refill
start_at = time.perf_counter()
time_to_refill = CAPACITY / TOKENS_PER_SECOND
while time.perf_counter() - start_at < time_to_refill:
await asyncio.sleep(time_to_refill)
# This should take roughly zero time
start_at = time.perf_counter()
for _ in range(CAPACITY):
await bucket.take()
end_at = time.perf_counter()
delta = end_at - start_at
await assert_close_to_zero(delta, CAPACITY)
def test_token_bucket_take_nowait():
bucket = TokenBucket(1, 10)
assert bucket.can_take(10)
bucket.take_nowait(10)
assert not bucket.can_take(1)
with pytest.raises(NotEnoughTokens):
bucket.take_nowait(1)
async def test_token_bucket_initial_tokens():
CAPACITY = 10
bucket = TokenBucket(1000, CAPACITY)
start_at = time.perf_counter()
for _ in range(CAPACITY):
await bucket.take()
end_at = time.perf_counter()
delta = end_at - start_at
await assert_close_to_zero(delta, CAPACITY)
async def test_token_bucket_hits_limit():
bucket = TokenBucket(1000, 10)
bucket.take_nowait(10)
start_at = time.perf_counter()
# first 10 tokens should be roughly instant
# next 10 tokens should each take 1/1000th second each to generate.
while True:
if bucket.can_take(10):
break
else:
await asyncio.sleep(0)
end_at = time.perf_counter()
# we use a zero-measure of 20 to account for the loop overhead.
zero = await measure_zero(10)
expected_delta = 10 / 1000 + zero
delta = end_at - start_at
# allow up to 10% difference in expected time
assert_fuzzy_equal(delta, expected_delta, allowed_drift=0.1)
async def test_token_bucket_hits_limit():
CAPACITY = 50
TOKENS_PER_SECOND = 1000
bucket = TokenBucket(TOKENS_PER_SECOND, CAPACITY)
bucket.take_nowait(CAPACITY)
start_at = time.perf_counter()
# first CAPACITY tokens should be roughly instant
# next CAPACITY tokens should each take 1/TOKENS_PER_SECOND second each to generate.
while True:
if bucket.can_take(CAPACITY):
break
else:
await asyncio.sleep(0)
end_at = time.perf_counter()
# we use a zero-measure of CAPACITY loops to account for the loop overhead.
zero = await measure_zero(CAPACITY)
expected_delta = CAPACITY / TOKENS_PER_SECOND + zero
delta = end_at - start_at
# allow up to 10% difference in expected time
assert_fuzzy_equal(delta, expected_delta, allowed_drift=0.1)
async def test_token_bucket_can_take():
bucket = TokenBucket(1, 10)
assert bucket.can_take() is True # can take 1
assert bucket.can_take(
bucket.get_num_tokens()) is True # can take full capacity
await bucket.take(10) # empty the bucket
assert bucket.can_take() is False
async def test_token_bucket_initial_tokens():
bucket = TokenBucket(1000, 10)
start_at = time.perf_counter()
for _ in range(10):
await bucket.take()
end_at = time.perf_counter()
delta = end_at - start_at
# since the bucket starts out full the loop
# should take near zero time
expected = await measure_zero(10)
# drift is allowed to be up to 1000% since we're working with very small
# numbers.
assert_fuzzy_equal(delta, expected, allowed_drift=10)
async def test_token_bucket_get_num_tokens():
bucket = TokenBucket(1, 10)
# starts at full capacity
assert bucket.get_num_tokens() == 10
await bucket.take(5)
assert 5 <= bucket.get_num_tokens() <= 5.1
await bucket.take(bucket.get_num_tokens())
assert 0 <= bucket.get_num_tokens() <= 0.1
async def maybe_connect_more_peers(self) -> None:
rate_limiter = TokenBucket(
rate=1 / PEER_CONNECT_INTERVAL,
capacity=MAX_SEQUENTIAL_PEER_CONNECT,
)
# We set this to 0 so that upon startup (when our RoutingTable will have only a few
# entries) we use the less restrictive filter function and get as many connection
# candidates as possible.
last_candidates_count = 0
while self.manager.is_running:
if self.is_full:
await asyncio.sleep(PEER_CONNECT_INTERVAL)
continue
await rate_limiter.take()
if last_candidates_count >= self.available_slots:
head = await self.get_chain_head()
genesis_hash = await self.get_genesis_hash()
fork_blocks = extract_fork_blocks(self.vm_configuration)
should_skip = functools.partial(
skip_candidate_if_on_list_or_fork_mismatch,
genesis_hash,
head.block_number,
fork_blocks,
)
else:
self.logger.debug(
"Didn't get enough candidates last time, falling back to skipping "
"only peers that are blacklisted or already connected to")
should_skip = skip_candidate_if_on_list # type: ignore
candidate_counts = await asyncio.gather(*(
self._add_peers_from_backend(backend, should_skip)
for backend in self.peer_backends
))
last_candidates_count = sum(candidate_counts)
async def test_token_bucket_refills_itself():
bucket = TokenBucket(1000, 10)
# consume all of the tokens
for _ in range(10):
await bucket.take()
# enough time for the bucket to fully refill
await asyncio.sleep(20 / 1000)
start_at = time.perf_counter()
for _ in range(10):
await bucket.take()
end_at = time.perf_counter()
delta = end_at - start_at
# since the capacity should have been fully refilled, second loop time
# should take near zero time
expected = await measure_zero(10)
# drift is allowed to be up to 300% since we're working with very small
# numbers, and the performance in CI varies widely.
assert_fuzzy_equal(delta, expected, allowed_drift=3)
class ResponseCandidateStream(
PeerSubscriber,
BaseService,
Generic[TRequestPayload, TResponsePayload]):
#
# PeerSubscriber
#
@property
def subscription_msg_types(self) -> FrozenSet[Type[CommandAPI]]:
return frozenset({self.response_msg_type})
msg_queue_maxsize = 100
response_timeout: float = ROUND_TRIP_TIMEOUT
pending_request: Tuple[float, 'asyncio.Future[TResponsePayload]'] = None
_peer: BasePeer
def __init__(
self,
peer: BasePeer,
response_msg_type: Type[CommandAPI],
token: CancelToken) -> None:
super().__init__(token)
self._peer = peer
self.response_msg_type = response_msg_type
self._lock = asyncio.Lock()
# token bucket for limiting timeouts.
# - Refills at 1-token every 5 minutes
# - Max capacity of 3 tokens
self.timeout_bucket = TokenBucket(TIMEOUT_BUCKET_RATE, TIMEOUT_BUCKET_CAPACITY)
async def payload_candidates(
self,
request: RequestAPI[TRequestPayload],
tracker: BasePerformanceTracker[RequestAPI[TRequestPayload], Any],
*,
timeout: float = None) -> AsyncGenerator[TResponsePayload, None]:
"""
Make a request and iterate through candidates for a valid response.
To mark a response as valid, use `complete_request`. After that call, payload
candidates will stop arriving.
"""
total_timeout = self.response_timeout if timeout is None else timeout
# The _lock ensures that we never have two concurrent requests to a
# single peer for a single command pair in flight.
try:
await self.wait(self._lock.acquire(), timeout=total_timeout * NUM_QUEUED_REQUESTS)
except TimeoutError:
raise AlreadyWaiting(
f"Timed out waiting for {self.response_msg_name} request lock "
f"or peer: {self._peer}"
)
start_at = time.perf_counter()
try:
self._request(request)
while self._is_pending():
timeout_remaining = max(0, total_timeout - (time.perf_counter() - start_at))
try:
yield await self._get_payload(timeout_remaining)
except TimeoutError as err:
tracker.record_timeout(total_timeout)
# If the peer has timeoud out too many times, desconnect
# and blacklist them
try:
self.timeout_bucket.take_nowait()
except NotEnoughTokens:
self.logger.warning(
"Blacklisting and disconnecting from %s due to too many timeouts",
self._peer,
)
self._peer.connection_tracker.record_blacklist(
self._peer.remote,
BLACKLIST_SECONDS_TOO_MANY_TIMEOUTS,
f"Too many timeouts: {err}",
)
self._peer.disconnect_nowait(DisconnectReason.timeout)
await self.cancellation()
finally:
raise
finally:
self._lock.release()
@property
def response_msg_name(self) -> str:
return self.response_msg_type.__name__
def complete_request(self) -> None:
if self.pending_request is None:
self.logger.warning("`complete_request` was called when there was no pending request")
self.pending_request = None
#
# Service API
#
async def _run(self) -> None:
self.logger.debug("Launching %r", self)
with self.subscribe_peer(self._peer):
while self.is_operational:
peer, cmd, msg = await self.wait(self.msg_queue.get())
if peer != self._peer:
self.logger.error("Unexpected peer: %s expected: %s", peer, self._peer)
continue
elif isinstance(cmd, self.response_msg_type):
await self._handle_msg(cast(TResponsePayload, msg))
else:
self.logger.warning("Unexpected payload type: %s", cmd.__class__.__name__)
async def _handle_msg(self, msg: TResponsePayload) -> None:
if self.pending_request is None:
self.logger.debug(
"Got unexpected %s payload from %s", self.response_msg_name, self._peer
)
return
send_time, future = self.pending_request
self.last_response_time = time.perf_counter() - send_time
try:
future.set_result(msg)
except asyncio.InvalidStateError:
self.logger.debug(
"%s received a message response, but future was already done",
self,
)
async def _get_payload(self, timeout: float) -> TResponsePayload:
send_time, future = self.pending_request
try:
payload = await self.wait(future, timeout=timeout)
finally:
self.pending_request = None
# payload might be invalid, so prepare for another call to _get_payload()
self.pending_request = (send_time, asyncio.Future())
return payload
def _request(self, request: RequestAPI[TRequestPayload]) -> None:
if not self._lock.locked():
# This is somewhat of an invariant check but since there the
# linkage between the lock and this method are loose this sanity
# check seems appropriate.
raise Exception("Invariant: cannot issue a request without an acquired lock")
self._peer.sub_proto.send_request(request)
future: 'asyncio.Future[TResponsePayload]' = asyncio.Future()
self.pending_request = (time.perf_counter(), future)
def _is_pending(self) -> bool:
return self.pending_request is not None
async def _cleanup(self) -> None:
if self.pending_request is not None:
self.logger.debug("Stream %r shutting down, cancelling the pending request", self)
_, future = self.pending_request
try:
future.set_exception(PeerConnectionLost(
f"Pending request can't complete: {self} is shutting down"
))
except asyncio.InvalidStateError:
self.logger.debug(
"%s cancelled pending future in cleanup, but it was already done",
self,
)
def __del__(self) -> None:
if self.pending_request is not None:
_, future = self.pending_request
if future.cancel():
self.logger.debug("Forcefully cancelled a pending response in %s", self)
def deregister_peer(self, peer: BasePeer) -> None:
if self.pending_request is not None:
self.logger.debug("Peer stream %r shutting down, cancelling the pending request", self)
_, future = self.pending_request
try:
future.set_exception(PeerConnectionLost(
f"Pending request can't complete: {self} peer went offline"
))
except asyncio.InvalidStateError:
self.logger.debug(
"%s cancelled pending future in deregister, but it was already done",
self,
)
def __repr__(self) -> str:
return f'<ResponseCandidateStream({self._peer!s}, {self.response_msg_type!r})>'
class RegularChainBodySyncer(BaseBodyChainSyncer):
"""
Sync with the Ethereum network by fetching block headers/bodies and importing them.
Here, the run() method will execute the sync loop forever, until our CancelToken is triggered.
"""
def __init__(self,
chain: AsyncChainAPI,
db: BaseAsyncChainDB,
peer_pool: ETHPeerPool,
header_syncer: HeaderSyncerAPI,
block_importer: BaseBlockImporter,
token: CancelToken = None) -> None:
super().__init__(chain, db, peer_pool, header_syncer, token)
# track when block bodies are downloaded, so that blocks can be imported
self._block_import_tracker = OrderedTaskPreparation(
BlockImportPrereqs,
id_extractor=attrgetter('hash'),
# make sure that a block is not imported until the parent block is imported
dependency_extractor=attrgetter('parent_hash'),
# Avoid problems by keeping twice as much data as the import queue size
max_depth=BLOCK_IMPORT_QUEUE_SIZE * 2,
)
self._block_importer = block_importer
# Track if any headers have been received yet
self._got_first_header = asyncio.Event()
# Rate limit the block import logs
self._import_log_limiter = TokenBucket(
0.33, # show about one log per 3 seconds
5, # burst up to 5 logs after a lag
)
# the queue of blocks that are downloaded and ready to be imported
self._import_queue: 'asyncio.Queue[BlockAPI]' = asyncio.Queue(BLOCK_IMPORT_QUEUE_SIZE)
self._import_active = asyncio.Lock()
async def _run(self) -> None:
head = await self.wait(self.db.coro_get_canonical_head())
self._block_import_tracker.set_finished_dependency(head)
self.run_daemon_task(self._launch_prerequisite_tasks())
self.run_daemon_task(self._assign_body_download_to_peers())
self.run_daemon_task(self._import_ready_blocks())
self.run_daemon_task(self._preview_ready_blocks())
self.run_daemon_task(self._display_stats())
await super()._run()
def register_peer(self, peer: BasePeer) -> None:
# when a new peer is added to the pool, add it to the idle peer list
super().register_peer(peer)
self._body_peers.put_nowait(cast(ETHPeer, peer))
async def _should_skip_header(self, header: BlockHeaderAPI) -> bool:
"""
Should we skip trying to import this header?
Return True if the syncing of header appears to be complete.
This is fairly relaxed about the definition, preferring speed over slow precision.
"""
return await self.db.coro_exists(header.state_root)
async def _launch_prerequisite_tasks(self) -> None:
"""
Watch for new headers to be added to the queue, and add the prerequisite
tasks (downloading block bodies) as they become available.
"""
async for headers in self._sync_from_headers(
self._block_import_tracker,
self._should_skip_header):
# Sometimes duplicates are added to the queue, when switching from one sync to another.
# We can simply ignore them.
new_headers = tuple(h for h in headers if h not in self._block_body_tasks)
# if the output queue gets full, hang until there is room
await self.wait(self._block_body_tasks.add(new_headers))
def _mark_body_download_complete(
self,
batch_id: int,
completed_headers: Sequence[BlockHeaderAPI]) -> None:
super()._mark_body_download_complete(batch_id, completed_headers)
self._block_import_tracker.finish_prereq(
BlockImportPrereqs.STORE_BLOCK_BODIES,
completed_headers,
)
async def _preview_ready_blocks(self) -> None:
"""
Wait for block bodies to be downloaded, then compile the blocks and
preview them to the importer.
It's important to do this in a separate step from importing so that
previewing can get ahead of import by a few blocks.
"""
await self.wait(self._got_first_header.wait())
while self.is_operational:
# This tracker waits for all prerequisites to be complete, and returns headers in
# order, so that each header's parent is already persisted.
get_ready_coro = self._block_import_tracker.ready_tasks(1)
completed_headers = await self.wait(get_ready_coro)
if self._block_import_tracker.has_ready_tasks():
# Even after clearing out a big batch, there is no available capacity, so
# pause any coroutines that might wait for capacity
self._db_buffer_capacity.clear()
else:
# There is available capacity, let any waiting coroutines continue
self._db_buffer_capacity.set()
header = completed_headers[0]
block = self._header_to_block(header)
# Put block in short queue for import, wait here if queue is full
await self.wait(self._import_queue.put(block))
# Load the state root of the parent header
try:
parent_state_root = self._block_hash_to_state_root[header.parent_hash]
except KeyError:
# For the very first header that we load, we have to look up the parent's
# state from the database:
parent = await self.chain.coro_get_block_header_by_hash(header.parent_hash)
parent_state_root = parent.state_root
# Emit block for preview
# - look up the addresses referenced by the transaction (eg~ sender and recipient)
# - execute the block ahead of time to start collecting any missing state
# - store the header (for future evm execution that might look up old block hashes)
await self._block_importer.preview_transactions(
header,
block.transactions,
parent_state_root,
)
async def _import_ready_blocks(self) -> None:
"""
Wait for block bodies to be downloaded, then compile the blocks and
preview them to the importer.
"""
await self.wait(self._got_first_header.wait())
while self.is_operational:
if self._import_queue.empty():
if self._import_active.locked():
self._import_active.release()
waiting_for_next_block = Timer()
block = await self.wait(self._import_queue.get())
if not self._import_active.locked():
self.logger.info(
"Waited %.1fs for %s body",
waiting_for_next_block.elapsed,
block.header,
)
await self._import_active.acquire()
await self._import_block(block)
async def _import_block(self, block: BlockAPI) -> None:
timer = Timer()
_, new_canonical_blocks, old_canonical_blocks = await self.wait(
self._block_importer.import_block(block)
)
# how much is the imported block's header behind the current time?
lag = time.time() - block.header.timestamp
humanized_lag = humanize_seconds(lag)
if new_canonical_blocks == (block,):
# simple import of a single new block.
# decide whether to log to info or debug, based on log rate
if self._import_log_limiter.can_take(1):
log_fn = self.logger.info
self._import_log_limiter.take_nowait(1)
else:
log_fn = self.logger.debug
log_fn(
"Imported block %d (%d txs) in %.2f seconds, with %s lag",
block.number,
len(block.transactions),
timer.elapsed,
humanized_lag,
)
elif not new_canonical_blocks:
# imported block from a fork.
self.logger.info(
"Imported non-canonical block %d (%d txs) in %.2f seconds, with %s lag",
block.number,
len(block.transactions),
timer.elapsed,
humanized_lag,
)
elif old_canonical_blocks:
self.logger.info(
"Chain Reorganization: Imported block %d (%d txs) in %.2f seconds, "
"%d blocks discarded and %d new canonical blocks added, with %s lag",
block.number,
len(block.transactions),
timer.elapsed,
len(old_canonical_blocks),
len(new_canonical_blocks),
humanized_lag,
)
else:
raise Exception("Invariant: unreachable code path")
def _header_to_block(self, header: BlockHeaderAPI) -> BlockAPI:
"""
This method converts a header that was queued up for sync into its full block
representation. It may not be called until after the body is marked as fully
downloaded, as tracked by self._block_import_tracker.
"""
vm_class = self.chain.get_vm_class(header)
block_class = vm_class.get_block_class()
if _is_body_empty(header):
transactions: List[SignedTransactionAPI] = []
uncles: List[BlockHeaderAPI] = []
else:
body = self._pending_bodies.pop(header)
tx_class = block_class.get_transaction_class()
transactions = [tx_class.from_base_transaction(tx)
for tx in body.transactions]
uncles = body.uncles
return block_class(header, transactions, uncles)
async def _display_stats(self) -> None:
self.logger.debug("Regular sync waiting for first header to arrive")
await self.wait(self._got_first_header.wait())
self.logger.debug("Regular sync first header arrived")
while self.is_operational:
await self.sleep(5)
self.logger.debug(
"(progress, queued, max) of bodies, receipts: %r. Write capacity? %s Importing? %s",
[(q.num_in_progress(), len(q), q._maxsize) for q in (
self._block_body_tasks,
)],
self._db_buffer_capacity.is_set(),
self._import_active.locked(),
)
class ExchangeManager(Generic[TRequestPayload, TResponsePayload, TResult]):
_response_stream: ResponseCandidateStream[TRequestPayload, TResponsePayload] = None
def __init__(
self,
peer: BasePeer,
listening_for: Type[CommandAPI],
cancel_token: CancelToken) -> None:
self._peer = peer
self._cancel_token = cancel_token
self._response_command_type = listening_for
# This TokenBucket allows for the occasional invalid response at a
# maximum rate of 1-per-10-minutes and allowing up to two in quick
# succession. We *allow* invalid responses because the ETH protocol
# doesn't have strong correlation between request/response and certain
# networking conditions can result in us interpreting a legitimate
# message as an invalid response if messages arrive out of order or
# late.
self._invalid_response_bucket = TokenBucket(1 / 600, 2)
async def launch_service(self) -> None:
if self._cancel_token.triggered:
raise PeerConnectionLost("Peer %s is gone. Ignoring new requests to it" % self._peer)
self._response_stream = ResponseCandidateStream(
self._peer,
self._response_command_type,
self._cancel_token,
)
self._peer.run_daemon(self._response_stream)
await self._peer.wait(self._response_stream.events.started.wait())
@property
def is_operational(self) -> bool:
return self.service is not None and self.service.is_operational
async def get_result(
self,
request: RequestAPI[TRequestPayload],
normalizer: BaseNormalizer[TResponsePayload, TResult],
validate_result: Callable[[TResult], None],
payload_validator: Callable[[TResponsePayload], None],
tracker: BasePerformanceTracker[RequestAPI[TRequestPayload], TResult],
timeout: float = None) -> TResult:
if not self.is_operational:
if self.service is None or not self.service.is_cancelled:
raise ValidationError(
f"Must call `launch_service` before sending request to {self._peer}"
)
else:
raise PeerConnectionLost(
f"Response stream closed before sending request to {self._peer}"
)
stream = self._response_stream
async for payload in stream.payload_candidates(request, tracker, timeout=timeout):
try:
payload_validator(payload)
if normalizer.is_normalization_slow:
result = await stream._run_in_executor(
None,
normalizer.normalize_result,
payload
)
else:
result = normalizer.normalize_result(payload)
validate_result(result)
except ValidationError as err:
self.service.logger.debug(
"Response validation failed for pending %s request from peer %s: %s",
stream.response_msg_name,
self._peer,
err,
)
try:
self._invalid_response_bucket.take_nowait()
except NotEnoughTokens:
self.service.logger.warning(
"Blacklisting and disconnecting from %s due to too many invalid responses",
self._peer,
)
self._peer.disconnect_nowait(DisconnectReason.bad_protocol)
await self.service.cancellation()
# re-raise the outer ValidationError exception
raise err
else:
continue
else:
tracker.record_response(
stream.last_response_time,
request,
result,
)
stream.complete_request()
return result
raise PeerConnectionLost(f"Response stream of {self._peer} was apparently closed")
@property
def service(self) -> BaseService:
"""
This service that needs to be running for calls to execute properly
"""
return self._response_stream
class RegularChainBodySyncer(BaseBodyChainSyncer):
"""
Sync with the Ethereum network by fetching block headers/bodies and importing them.
Here, the run() method will execute the sync loop forever, until our CancelToken is triggered.
"""
def __init__(self,
chain: BaseAsyncChain,
db: BaseAsyncChainDB,
peer_pool: ETHPeerPool,
header_syncer: HeaderSyncerAPI,
block_importer: BaseBlockImporter,
token: CancelToken = None) -> None:
super().__init__(chain, db, peer_pool, header_syncer, token)
# track when block bodies are downloaded, so that blocks can be imported
self._block_import_tracker = OrderedTaskPreparation(
BlockImportPrereqs,
id_extractor=attrgetter('hash'),
# make sure that a block is not imported until the parent block is imported
dependency_extractor=attrgetter('parent_hash'),
)
self._block_importer = block_importer
# Track if any headers have been received yet
self._got_first_header = asyncio.Event()
# Rate limit the block import logs
self._import_log_limiter = TokenBucket(
0.33, # show about one log per 3 seconds
5, # burst up to 5 logs after a lag
)
async def _run(self) -> None:
head = await self.wait(self.db.coro_get_canonical_head())
self._block_import_tracker.set_finished_dependency(head)
self.run_daemon_task(self._launch_prerequisite_tasks())
self.run_daemon_task(self._assign_body_download_to_peers())
self.run_daemon_task(self._import_ready_blocks())
self.run_daemon_task(self._display_stats())
await super()._run()
def register_peer(self, peer: BasePeer) -> None:
# when a new peer is added to the pool, add it to the idle peer list
super().register_peer(peer)
self._body_peers.put_nowait(cast(ETHPeer, peer))
async def _should_skip_header(self, header: BlockHeader) -> bool:
"""
Should we skip trying to import this header?
Return True if the syncing of header appears to be complete.
This is fairly relaxed about the definition, preferring speed over slow precision.
"""
return await self.db.coro_exists(header.state_root)
async def _launch_prerequisite_tasks(self) -> None:
"""
Watch for new headers to be added to the queue, and add the prerequisite
tasks (downloading block bodies) as they become available.
"""
async for headers in self._sync_from_headers(
self._block_import_tracker, self._should_skip_header):
# Sometimes duplicates are added to the queue, when switching from one sync to another.
# We can simply ignore them.
new_headers = tuple(h for h in headers
if h not in self._block_body_tasks)
# if the output queue gets full, hang until there is room
await self.wait(self._block_body_tasks.add(new_headers))
def _mark_body_download_complete(
self, batch_id: int, completed_headers: Tuple[BlockHeader,
...]) -> None:
super()._mark_body_download_complete(batch_id, completed_headers)
self._block_import_tracker.finish_prereq(
BlockImportPrereqs.StoreBlockBodies,
completed_headers,
)
async def _import_ready_blocks(self) -> None:
"""
Wait for block bodies to be downloaded, then import the blocks.
"""
await self.wait(self._got_first_header.wait())
while self.is_operational:
timer = Timer()
# This tracker waits for all prerequisites to be complete, and returns headers in
# order, so that each header's parent is already persisted.
get_ready_coro = self._block_import_tracker.ready_tasks(
BLOCK_IMPORT_QUEUE_SIZE_TARGET)
completed_headers = await self.wait(get_ready_coro)
if self._block_import_tracker.has_ready_tasks():
# Even after clearing out a big batch, there is no available capacity, so
# pause any coroutines that might wait for capacity
self._db_buffer_capacity.clear()
else:
# There is available capacity, let any waiting coroutines continue
self._db_buffer_capacity.set()
await self._import_blocks(completed_headers)
head = await self.wait(self.db.coro_get_canonical_head())
self.logger.info(
"Synced chain segment with %d blocks in %.2f seconds, new head: %s",
len(completed_headers),
timer.elapsed,
head,
)
async def _import_blocks(self, headers: Tuple[BlockHeader, ...]) -> None:
"""
Import the blocks for the corresponding headers
:param headers: headers that have the block bodies downloaded
"""
unimported_blocks = self._headers_to_blocks(headers)
for block in unimported_blocks:
timer = Timer()
_, new_canonical_blocks, old_canonical_blocks = await self.wait(
self._block_importer.import_block(block))
if new_canonical_blocks == (block, ):
# simple import of a single new block.
# decide whether to log to info or debug, based on log rate
if self._import_log_limiter.can_take(1):
log_fn = self.logger.info
self._import_log_limiter.take_nowait(1)
else:
log_fn = self.logger.debug
log_fn(
"Imported block %d (%d txs) in %.2f seconds, with %s lag",
block.number,
len(block.transactions),
timer.elapsed,
humanize_seconds(time.time() - block.header.timestamp),
)
elif not new_canonical_blocks:
# imported block from a fork.
self.logger.info(
"Imported non-canonical block %d (%d txs) in %.2f seconds",
block.number, len(block.transactions), timer.elapsed)
elif old_canonical_blocks:
self.logger.info(
"Chain Reorganization: Imported block %d (%d txs) in %.2f "
"seconds, %d blocks discarded and %d new canonical blocks added",
block.number,
len(block.transactions),
timer.elapsed,
len(old_canonical_blocks),
len(new_canonical_blocks),
)
else:
raise Exception("Invariant: unreachable code path")
@to_tuple
def _headers_to_blocks(
self, headers: Iterable[BlockHeader]) -> Iterable[BaseBlock]:
for header in headers:
vm_class = self.chain.get_vm_class(header)
block_class = vm_class.get_block_class()
if _is_body_empty(header):
transactions: List[BaseTransaction] = []
uncles: List[BlockHeader] = []
else:
body = self._pending_bodies.pop(header)
tx_class = block_class.get_transaction_class()
transactions = [
tx_class.from_base_transaction(tx)
for tx in body.transactions
]
uncles = body.uncles
yield block_class(header, transactions, uncles)
async def _display_stats(self) -> None:
self.logger.debug("Regular sync waiting for first header to arrive")
await self.wait(self._got_first_header.wait())
self.logger.debug("Regular sync first header arrived")
while self.is_operational:
await self.sleep(5)
self.logger.debug(
"(in progress, queued, max size) of bodies, receipts: %r. Write capacity? %s",
[(q.num_in_progress(), len(q), q._maxsize)
for q in (self._block_body_tasks, )],
"yes" if self._db_buffer_capacity.is_set() else "no",
)
