class Replica(HasActionQueue, MessageProcessor): STASHED_CHECKPOINTS_BEFORE_CATCHUP = 1 HAS_NO_PRIMARY_WARN_THRESCHOLD = 10 def __init__(self, node: 'plenum.server.node.Node', instId: int, config=None, isMaster: bool = False, bls_bft_replica: BlsBftReplica = None, metrics: MetricsCollector = NullMetricsCollector(), get_current_time=None, get_time_for_3pc_batch=None): """ Create a new replica. :param node: Node on which this replica is located :param instId: the id of the protocol instance the replica belongs to :param isMaster: is this a replica of the master protocol instance """ HasActionQueue.__init__(self) self.get_current_time = get_current_time or time.perf_counter self.get_time_for_3pc_batch = get_time_for_3pc_batch or node.utc_epoch # self.stats = Stats(TPCStat) self.config = config or getConfig() self.metrics = metrics self.node = node self.instId = instId self.name = self.generateName(node.name, self.instId) self.logger = getlogger(self.name) self.validator = ReplicaValidator(self) self.outBox = deque() """ This queue is used by the replica to send messages to its node. Replica puts messages that are consumed by its node """ self.inBox = deque() """ This queue is used by the replica to receive messages from its node. Node puts messages that are consumed by the replica """ self.inBoxStash = deque() """ If messages need to go back on the queue, they go here temporarily and are put back on the queue on a state change """ self._is_master = isMaster # Dictionary to keep track of the which replica was primary during each # view. Key is the view no and value is the name of the primary # replica during that view self.primaryNames = OrderedDict() # type: OrderedDict[int, str] # Flag being used for preterm exit from the loop in the method # `processStashedMsgsForNewWaterMarks`. See that method for details. self.consumedAllStashedMsgs = True self._freshness_checker = FreshnessChecker( freshness_timeout=self.config.STATE_FRESHNESS_UPDATE_INTERVAL) self._bls_bft_replica = bls_bft_replica self._state_root_serializer = state_roots_serializer # Did we log a message about getting request while absence of primary self.warned_no_primary = False self._consensus_data = ConsensusSharedData( self.name, self.node.poolManager.node_names_ordered_by_rank(), self.instId, self.isMaster) self._internal_bus = InternalBus() self._external_bus = ExternalBus(send_handler=self.send) self.stasher = self._init_replica_stasher() self._subscription = Subscription() self._bootstrap_consensus_data() self._subscribe_to_external_msgs() self._subscribe_to_internal_msgs() self._checkpointer = self._init_checkpoint_service() self._ordering_service = self._init_ordering_service() self._message_req_service = self._init_message_req_service() self._view_change_service = self._init_view_change_service() for ledger_id in self.ledger_ids: self.register_ledger(ledger_id) @property def internal_bus(self): return self._internal_bus def cleanup(self): # Aggregate all the currently forwarded requests req_keys = set() for msg in self.inBox: if isinstance(msg, ReqKey): req_keys.add(msg.digest) for req_queue in self._ordering_service.requestQueues.values(): for req_key in req_queue: req_keys.add(req_key) for pp in self._ordering_service.sent_preprepares.values(): for req_key in pp.reqIdr: req_keys.add(req_key) for pp in self._ordering_service.prePrepares.values(): for req_key in pp.reqIdr: req_keys.add(req_key) for req_key in req_keys: if req_key in self.requests: self.requests.ordered_by_replica(req_key) self.requests.free(req_key) self._ordering_service.cleanup() self._checkpointer.cleanup() self._subscription.unsubscribe_all() self.stasher.unsubscribe_from_all() @property def external_bus(self): return self._external_bus @property def isMaster(self): return self._is_master @isMaster.setter def isMaster(self, value): self._is_master = value self._consensus_data.is_master = value def _bootstrap_consensus_data(self): self._consensus_data.requests = self.requests self._consensus_data.node_mode = self.node.mode self._consensus_data.quorums = self.quorums def set_primaries(self, primaries): self._consensus_data.primaries = primaries def _subscribe_to_external_msgs(self): # self._subscription.subscribe(self._external_bus, ReqKey, self.readyFor3PC) pass def _process_new_view_accepted(self, msg: NewViewAccepted): self.clear_requests_and_fix_last_ordered() def _subscribe_to_internal_msgs(self): self._subscription.subscribe(self.internal_bus, Ordered, self._send_ordered) self._subscription.subscribe(self.internal_bus, NeedBackupCatchup, self._caught_up_backup) self._subscription.subscribe(self.internal_bus, ReqKey, self.readyFor3PC) self._subscription.subscribe(self.internal_bus, RaisedSuspicion, self._process_suspicious_node) self._subscription.subscribe(self.internal_bus, NewViewAccepted, self._process_new_view_accepted) def register_ledger(self, ledger_id): # Using ordered set since after ordering each PRE-PREPARE, # the request key is removed, so fast lookup and removal of # request key is needed. Need the collection to be ordered since # the request key needs to be removed once its ordered if ledger_id not in self._ordering_service.requestQueues: self._ordering_service.requestQueues[ledger_id] = OrderedSet() if ledger_id != AUDIT_LEDGER_ID: self._freshness_checker.register_ledger( ledger_id=ledger_id, initial_time=self.get_time_for_3pc_batch()) @property def last_prepared_before_view_change(self): return self._consensus_data.legacy_last_prepared_before_view_change @last_prepared_before_view_change.setter def last_prepared_before_view_change(self, lst): self._consensus_data.legacy_last_prepared_before_view_change = lst @property def h(self) -> int: return self._consensus_data.low_watermark @property def H(self) -> int: return self._consensus_data.high_watermark @property def last_ordered_3pc(self) -> tuple: return self._ordering_service.last_ordered_3pc @last_ordered_3pc.setter def last_ordered_3pc(self, key3PC): self._ordering_service.last_ordered_3pc = key3PC @property def lastPrePrepareSeqNo(self): return self._ordering_service.lastPrePrepareSeqNo @property def requests(self): return self.node.requests @property def ledger_ids(self): return self.node.ledger_ids @property def quorums(self): return self.node.quorums @property def utc_epoch(self): return self.node.utc_epoch() @staticmethod def generateName(nodeName: str, instId: int): """ Create and return the name for a replica using its nodeName and instanceId. Ex: Alpha:1 """ if isinstance(nodeName, str): # Because sometimes it is bytes (why?) if ":" in nodeName: # Because in some cases (for requested messages) it # already has ':'. This should be fixed. return nodeName return "{}:{}".format(nodeName, instId) @staticmethod def getNodeName(replicaName: str): return replicaName.split(":")[0] @property def isPrimary(self): """ Is this node primary? :return: True if this node is primary, False if not, None if primary status not known """ return self._consensus_data.is_primary @property def hasPrimary(self): return self.primaryName is not None @property def primaryName(self): """ Name of the primary replica of this replica's instance :return: Returns name if primary is known, None otherwise """ return self._consensus_data.primary_name @primaryName.setter def primaryName(self, value: Optional[str]) -> None: """ Set the value of isPrimary. :param value: the value to set isPrimary to """ if value is not None: self.warned_no_primary = False self.primaryNames[self.viewNo] = value self.compact_primary_names() if value != self._consensus_data.primary_name: self._consensus_data.primary_name = value self.logger.info( "{} setting primaryName for view no {} to: {}".format( self, self.viewNo, value)) if value is None: # Since the GC needs to happen after a primary has been # decided. return self._gc_before_new_view() def compact_primary_names(self): min_allowed_view_no = self.viewNo - 1 views_to_remove = [] for view_no in self.primaryNames: if view_no >= min_allowed_view_no: break views_to_remove.append(view_no) for view_no in views_to_remove: self.primaryNames.pop(view_no) def primaryChanged(self, primaryName): self._ordering_service.batches.clear() if self.isMaster: # Since there is no temporary state data structure and state root # is explicitly set to correct value for lid in self.ledger_ids: try: ledger = self.node.getLedger(lid) except KeyError: continue ledger.reset_uncommitted() self.primaryName = primaryName self._setup_for_non_master_after_view_change(self.viewNo) def on_view_change_start(self): if self.isMaster: lst = self._ordering_service.l_last_prepared_certificate_in_view() self._consensus_data.legacy_last_prepared_before_view_change = lst self.logger.info( '{} setting last prepared for master to {}'.format(self, lst)) def on_view_change_done(self): if self.isMaster: self.last_prepared_before_view_change = None self.stasher.process_all_stashed(STASH_VIEW_3PC) def _clear_all_3pc_msgs(self): self._ordering_service._clear_all_3pc_msgs() def clear_requests_and_fix_last_ordered(self): if self.isMaster: return self._internal_bus.send(CheckpointStabilized(self.last_ordered_3pc)) self._ordering_service._lastPrePrepareSeqNo = 0 self._ordering_service.last_ordered_3pc = (self.viewNo, 0) self._clear_all_3pc_msgs() def on_propagate_primary_done(self): if self.isMaster: # if this is a Primary that is re-connected (that is view change is not actually changed, # we just propagate it, then make sure that we did't break the sequence # of ppSeqNo self._checkpointer.update_watermark_from_3pc() elif not self.isPrimary: self._checkpointer.set_watermarks(low_watermark=0, high_watermark=sys.maxsize) def get_lowest_probable_prepared_certificate_in_view( self, view_no) -> Optional[int]: """ Return lowest pp_seq_no of the view for which can be prepared but choose from unprocessed PRE-PREPAREs and PREPAREs. """ # TODO: Naive implementation, dont need to iterate over the complete # data structures, fix this later seq_no_pp = SortedList() # pp_seq_no of PRE-PREPAREs # pp_seq_no of PREPAREs with count of PREPAREs for each seq_no_p = set() for (v, p) in self._ordering_service.prePreparesPendingPrevPP: if v == view_no: seq_no_pp.add(p) if v > view_no: break for ( v, p ), pr in self._ordering_service.preparesWaitingForPrePrepare.items(): if v == view_no and len(pr) >= self.quorums.prepare.value: seq_no_p.add(p) for n in seq_no_pp: if n in seq_no_p: return n return None def _setup_for_non_master_after_view_change(self, current_view): if not self.isMaster: for v in list(self.stashed_out_of_order_commits.keys()): if v < current_view: self.stashed_out_of_order_commits.pop(v) def is_primary_in_view(self, viewNo: int) -> Optional[bool]: """ Return whether this replica was primary in the given view """ if viewNo not in self.primaryNames: return False return self.primaryNames[viewNo] == self.name def isMsgForCurrentView(self, msg): """ Return whether this request's view number is equal to the current view number of this replica. """ viewNo = getattr(msg, "viewNo", None) return viewNo == self.viewNo def isPrimaryForMsg(self, msg) -> Optional[bool]: """ Return whether this replica is primary if the request's view number is equal this replica's view number and primary has been selected for the current view. Return None otherwise. :param msg: message """ return self.isPrimary if self.isMsgForCurrentView(msg) \ else self.is_primary_in_view(msg.viewNo) def isMsgFromPrimary(self, msg, sender: str) -> bool: """ Return whether this message was from primary replica :param msg: :param sender: :return: """ if self.isMsgForCurrentView(msg): return self.primaryName == sender try: return self.primaryNames[msg.viewNo] == sender except KeyError: return False def __repr__(self): return self.name @property def f(self) -> int: """ Return the number of Byzantine Failures that can be tolerated by this system. Equal to (N - 1)/3, where N is the number of nodes in the system. """ return self.node.f @property def viewNo(self): """ Return the current view number of this replica. """ return self._consensus_data.view_no @property def stashed_out_of_order_commits(self): # Commits which are not being ordered since commits with lower # sequence numbers have not been ordered yet. Key is the # viewNo and value a map of pre-prepare sequence number to commit # type: Dict[int,Dict[int,Commit]] return self._ordering_service.stashed_out_of_order_commits def send_3pc_batch(self): return self._ordering_service.send_3pc_batch() @staticmethod def batchDigest(reqs): return replica_batch_digest(reqs) def readyFor3PC(self, key: ReqKey): try: fin_req = self.requests[key.digest].finalised except KeyError: # Means that this request is outdated and is dropped from the main requests queue self.logger.debug( '{} reports request {} is ready for 3PC but it has been dropped ' 'from requests queue, ignore this request'.format(self, key)) return queue = self._ordering_service.requestQueues[ self.node.ledger_id_for_request(fin_req)] queue.add(key.digest) if not self.hasPrimary and len( queue ) >= self.HAS_NO_PRIMARY_WARN_THRESCHOLD and not self.warned_no_primary: self.logger.warning( '{} is getting requests but still does not have ' 'a primary so the replica will not process the request ' 'until a primary is chosen'.format(self)) self.warned_no_primary = True @measure_replica_time(MetricsName.SERVICE_REPLICA_QUEUES_TIME, MetricsName.SERVICE_BACKUP_REPLICAS_QUEUES_TIME) def serviceQueues(self, limit=None): """ Process `limit` number of messages in the inBox. :param limit: the maximum number of messages to process :return: the number of messages successfully processed """ # TODO should handle SuspiciousNode here r = self.dequeue_pre_prepares() # r += self.inBoxRouter.handleAllSync(self.inBox, limit) r += self._handle_external_messages(self.inBox, limit) r += self.send_3pc_batch() r += self._serviceActions() return r # Messages that can be processed right now needs to be added back to the # queue. They might be able to be processed later def _handle_external_messages(self, deq: deque, limit=None) -> int: """ Synchronously handle all items in a deque. :param deq: a deque of items to be handled by this router :param limit: the number of items in the deque to the handled :return: the number of items handled successfully """ count = 0 while deq and (not limit or count < limit): count += 1 msg = deq.popleft() external_msg, sender = msg if len(msg) == 2 else (msg, None) # TODO: get rid of appending instId to sender sender = self.generateName(sender, self.instId) self._external_bus.process_incoming(external_msg, sender) return count def _gc_before_new_view(self): # Trigger GC for all batches of old view # Clear any checkpoints, since they are valid only in a view # ToDo: Need to send a cmd like ViewChangeStart into internal bus # self._gc(self.last_ordered_3pc) self._ordering_service.gc(self.last_ordered_3pc) # ToDo: get rid of directly calling self._ordering_service._clear_prev_view_pre_prepares() # self._clear_prev_view_pre_prepares() def has_already_ordered(self, view_no, pp_seq_no): return compare_3PC_keys( (view_no, pp_seq_no), self.last_ordered_3pc) >= 0 def dequeue_pre_prepares(self): return self._ordering_service.dequeue_pre_prepares() def send(self, msg, to_nodes=None) -> None: """ Send a message to the node on which this replica resides. :param stat: :param rid: remote id of one recipient (sends to all recipients if None) :param msg: the message to send """ self.logger.trace("{} sending {}".format(self, msg.__class__.__name__), extra={ "cli": True, "tags": ['sending'] }) self.logger.trace("{} sending {}".format(self, msg)) if to_nodes: self.node.sendToNodes(msg, names=to_nodes) return self.outBox.append(msg) def revert_unordered_batches(self): """ Revert changes to ledger (uncommitted) and state made by any requests that have not been ordered. """ return self._ordering_service.revert_unordered_batches() def on_catch_up_finished(self, last_caught_up_3PC=None, master_last_ordered_3PC=None): if master_last_ordered_3PC and last_caught_up_3PC and \ compare_3PC_keys(master_last_ordered_3PC, last_caught_up_3PC) > 0: if self.isMaster: self._caught_up_till_3pc(last_caught_up_3PC) else: self._ordering_service.first_batch_after_catchup = True self._catchup_clear_for_backup() self.stasher.process_all_stashed(STASH_CATCH_UP) def discard_req_key(self, ledger_id, req_key): return self._ordering_service.discard_req_key(ledger_id, req_key) def _caught_up_backup(self, msg: NeedBackupCatchup): self._caught_up_till_3pc(msg.caught_up_till_3pc) def _caught_up_till_3pc(self, last_caught_up_3PC): self._ordering_service._caught_up_till_3pc(last_caught_up_3PC) self._checkpointer.caught_up_till_3pc(last_caught_up_3PC) def _catchup_clear_for_backup(self): if not self.isPrimary: self.outBox.clear() self._checkpointer.catchup_clear_for_backup() self._ordering_service.catchup_clear_for_backup() def _remove_ordered_from_queue(self, last_caught_up_3PC=None): """ Remove any Ordered that the replica might be sending to node which is less than or equal to `last_caught_up_3PC` if `last_caught_up_3PC` is passed else remove all ordered, needed in catchup """ to_remove = [] for i, msg in enumerate(self.outBox): if isinstance(msg, Ordered) and \ (not last_caught_up_3PC or compare_3PC_keys((msg.viewNo, msg.ppSeqNo), last_caught_up_3PC) >= 0): to_remove.append(i) self.logger.trace( '{} going to remove {} Ordered messages from outbox'.format( self, len(to_remove))) # Removing Ordered from queue but returning `Ordered` in order that # they should be processed. removed = [] for i in reversed(to_remove): removed.insert(0, self.outBox[i]) del self.outBox[i] return removed def _get_last_timestamp_from_state(self, ledger_id): if ledger_id == DOMAIN_LEDGER_ID: ts_store = self.node.db_manager.get_store(TS_LABEL) if ts_store: last_timestamp = ts_store.get_last_key() if last_timestamp: last_timestamp = int(last_timestamp.decode()) self.logger.debug( "Last ordered timestamp from store is : {}" "".format(last_timestamp)) return last_timestamp return None def get_ledgers_last_update_time(self) -> dict: if self._freshness_checker: return self._freshness_checker.get_last_update_time() def get_valid_req_ids_from_all_requests(self, reqs, invalid_indices): return [ req.key for idx, req in enumerate(reqs) if idx not in invalid_indices ] def report_suspicious_node(self, ex): if self.isMaster: self.node.reportSuspiciousNodeEx(ex) else: self.warn_suspicious_backup(ex.node, ex.reason, ex.code) def warn_suspicious_backup(self, nodeName, reason, code): self.logger.warning( "backup replica {} raised suspicion on node {} for {}; suspicion code " "is {}".format(self, nodeName, reason, code)) def set_validators(self, validators): self._consensus_data.set_validators(validators) def set_view_no(self, view_no): self._consensus_data.view_no = view_no def set_view_change_status(self, legacy_vc_in_progress): self._consensus_data.legacy_vc_in_progress = legacy_vc_in_progress def set_mode(self, mode): self._consensus_data.node_mode = mode def set_primaries_batch_needed(self, value): self._ordering_service.primaries_batch_needed = value def update_connecteds(self, connecteds: dict): self._external_bus.update_connecteds(connecteds) def _init_replica_stasher(self): return StashingRouter(self.config.REPLICA_STASH_LIMIT, buses=[self.internal_bus, self._external_bus], unstash_handler=self._add_to_inbox) def _process_suspicious_node(self, msg: RaisedSuspicion): if msg.inst_id != self.instId: return self.report_suspicious_node(msg.ex) def _send_ordered(self, msg: Ordered): self.send(msg) def _init_checkpoint_service(self) -> CheckpointService: return CheckpointService(data=self._consensus_data, bus=self.internal_bus, network=self._external_bus, stasher=self.stasher, db_manager=self.node.db_manager, metrics=self.metrics) def _init_ordering_service(self) -> OrderingService: return OrderingService( data=self._consensus_data, timer=self.node.timer, bus=self.internal_bus, network=self._external_bus, write_manager=self.node.write_manager, bls_bft_replica=self._bls_bft_replica, freshness_checker=self._freshness_checker, get_current_time=self.get_current_time, get_time_for_3pc_batch=self.get_time_for_3pc_batch, stasher=self.stasher, metrics=self.metrics) def _init_message_req_service(self) -> MessageReqService: return MessageReqService(data=self._consensus_data, bus=self.internal_bus, network=self._external_bus, metrics=self.metrics) def _init_view_change_service(self) -> ViewChangeService: return ViewChangeService(data=self._consensus_data, timer=self.node.timer, bus=self.internal_bus, network=self._external_bus, stasher=self.stasher) def _add_to_inbox(self, message): self.inBox.append(message)
class CheckpointService: STASHED_CHECKPOINTS_BEFORE_CATCHUP = 1 # TODO: Remove view_no from key after implementing INDY-1336 CheckpointKey = NamedTuple('CheckpointKey', [('view_no', int), ('pp_seq_no', int), ('digest', str)]) def __init__( self, data: ConsensusSharedData, bus: InternalBus, network: ExternalBus, stasher: StashingRouter, db_manager: DatabaseManager, metrics: MetricsCollector = NullMetricsCollector(), ): self._data = data self._bus = bus self._network = network self._stasher = stasher self._subscription = Subscription() self._validator = CheckpointMsgValidator(self._data) self._db_manager = db_manager self.metrics = metrics # Received checkpoints, mapping CheckpointKey -> List(node_alias) self._received_checkpoints = defaultdict( set) # type: Dict[CheckpointService.CheckpointKey, Set[str]] self._config = getConfig() self._logger = getlogger() self._subscription.subscribe(stasher, Checkpoint, self.process_checkpoint) self._subscription.subscribe(bus, Ordered, self.process_ordered) self._subscription.subscribe(bus, BackupSetupLastOrdered, self.process_backup_setup_last_ordered) self._subscription.subscribe(bus, NewViewAccepted, self.process_new_view_accepted) def cleanup(self): self._subscription.unsubscribe_all() @property def view_no(self): return self._data.view_no @property def is_master(self): return self._data.is_master @property def last_ordered_3pc(self): return self._data.last_ordered_3pc @measure_consensus_time(MetricsName.PROCESS_CHECKPOINT_TIME, MetricsName.BACKUP_PROCESS_CHECKPOINT_TIME) def process_checkpoint(self, msg: Checkpoint, sender: str) -> (bool, str): """ Process checkpoint messages :return: whether processed (True) or stashed (False) """ self._logger.info('{} processing checkpoint {} from {}'.format( self, msg, sender)) result, reason = self._validator.validate(msg) if result != PROCESS: return result, reason key = self._checkpoint_key(msg) self._received_checkpoints[key].add(sender) self._try_to_stabilize_checkpoint(key) self._start_catchup_if_needed(key) def process_backup_setup_last_ordered(self, msg: BackupSetupLastOrdered): if msg.inst_id != self._data.inst_id: return self.update_watermark_from_3pc() def process_ordered(self, ordered: Ordered): for batch_id in reversed(self._data.preprepared): if batch_id.pp_seq_no == ordered.ppSeqNo: self._add_to_checkpoint(batch_id.pp_seq_no, batch_id.view_no, ordered.auditTxnRootHash) return raise LogicError( "CheckpointService | Can't process Ordered msg because " "ppSeqNo {} not in preprepared".format(ordered.ppSeqNo)) def _start_catchup_if_needed(self, key: CheckpointKey): if self._have_own_checkpoint(key): return unknown_stabilized = self._unknown_stabilized_checkpoints() lag_in_checkpoints = len(unknown_stabilized) if lag_in_checkpoints <= self.STASHED_CHECKPOINTS_BEFORE_CATCHUP: return last_key = sorted(unknown_stabilized, key=lambda v: (v.view_no, v.pp_seq_no))[-1] if self.is_master: # TODO: This code doesn't seem to be needed, but it was there. Leaving just in case # tests explain why it was really needed. # self._logger.display( # '{} has lagged for {} checkpoints so updating watermarks to {}'.format( # self, lag_in_checkpoints, last_key.pp_seq_no)) # self.set_watermarks(low_watermark=last_key.pp_seq_no) if not self._data.is_primary: self._logger.display( '{} has lagged for {} checkpoints so the catchup procedure starts' .format(self, lag_in_checkpoints)) self._bus.send(NeedMasterCatchup()) else: self._logger.info( '{} has lagged for {} checkpoints so adjust last_ordered_3pc to {}, ' 'shift watermarks and clean collections'.format( self, lag_in_checkpoints, last_key.pp_seq_no)) # Adjust last_ordered_3pc, shift watermarks, clean operational # collections and process stashed messages which now fit between # watermarks # TODO: Actually we might need to process view_no from last_key as well, however # it wasn't processed before, and it will go away when INDY-1336 gets implemented key_3pc = (self.view_no, last_key.pp_seq_no) self._bus.send( NeedBackupCatchup(inst_id=self._data.inst_id, caught_up_till_3pc=key_3pc)) self.caught_up_till_3pc(key_3pc) def gc_before_new_view(self): self._reset_checkpoints() # ToDo: till_3pc_key should be None? self._remove_received_checkpoints(till_3pc_key=(self.view_no, 0)) def caught_up_till_3pc(self, caught_up_till_3pc): # TODO: Add checkpoint using audit ledger cp_seq_no = caught_up_till_3pc[ 1] // self._config.CHK_FREQ * self._config.CHK_FREQ self._mark_checkpoint_stable(cp_seq_no) def catchup_clear_for_backup(self): self._reset_checkpoints() self._remove_received_checkpoints() self.set_watermarks(low_watermark=0, high_watermark=sys.maxsize) def _add_to_checkpoint(self, ppSeqNo, view_no, audit_txn_root_hash): if ppSeqNo % self._config.CHK_FREQ != 0: return key = self.CheckpointKey(view_no=view_no, pp_seq_no=ppSeqNo, digest=audit_txn_root_hash) self._do_checkpoint(ppSeqNo, view_no, audit_txn_root_hash) self._try_to_stabilize_checkpoint(key) @measure_consensus_time(MetricsName.SEND_CHECKPOINT_TIME, MetricsName.BACKUP_SEND_CHECKPOINT_TIME) def _do_checkpoint(self, pp_seq_no, view_no, audit_txn_root_hash): self._logger.info( "{} sending Checkpoint {} view {} audit txn root hash {}".format( self, pp_seq_no, view_no, audit_txn_root_hash)) checkpoint = Checkpoint(self._data.inst_id, view_no, 0, pp_seq_no, audit_txn_root_hash) self._network.send(checkpoint) self._data.checkpoints.add(checkpoint) def _try_to_stabilize_checkpoint(self, key: CheckpointKey): if not self._have_quorum_on_received_checkpoint(key): return if not self._have_own_checkpoint(key): return self._mark_checkpoint_stable(key.pp_seq_no) def _mark_checkpoint_stable(self, pp_seq_no): self._data.stable_checkpoint = pp_seq_no stable_checkpoints = self._data.checkpoints.irange_key( min_key=pp_seq_no, max_key=pp_seq_no) if len(list(stable_checkpoints)) == 0: # TODO: Is it okay to get view_no like this? view_no = self._data.last_ordered_3pc[0] checkpoint = Checkpoint(instId=self._data.inst_id, viewNo=view_no, seqNoStart=0, seqNoEnd=pp_seq_no, digest=self._audit_txn_root_hash( view_no, pp_seq_no)) self._data.checkpoints.add(checkpoint) for cp in self._data.checkpoints.copy(): if cp.seqNoEnd < pp_seq_no: self._logger.trace("{} removing previous checkpoint {}".format( self, cp)) self._data.checkpoints.remove(cp) self.set_watermarks(low_watermark=pp_seq_no) self._remove_received_checkpoints(till_3pc_key=(self.view_no, pp_seq_no)) self._bus.send(CheckpointStabilized( (self.view_no, pp_seq_no))) # call OrderingService.gc() self._logger.info("{} marked stable checkpoint {}".format( self, pp_seq_no)) def set_watermarks(self, low_watermark: int, high_watermark: int = None): self._data.low_watermark = low_watermark self._data.high_watermark = self._data.low_watermark + self._config.LOG_SIZE \ if high_watermark is None else \ high_watermark self._logger.info('{} set watermarks as {} {}'.format( self, self._data.low_watermark, self._data.high_watermark)) self._stasher.process_all_stashed(STASH_WATERMARKS) def update_watermark_from_3pc(self): last_ordered_3pc = self.last_ordered_3pc if (last_ordered_3pc is not None) and (last_ordered_3pc[0] == self.view_no): self._logger.info( "update_watermark_from_3pc to {}".format(last_ordered_3pc)) self.set_watermarks(last_ordered_3pc[1]) else: self._logger.info( "try to update_watermark_from_3pc but last_ordered_3pc is None" ) def _remove_received_checkpoints(self, till_3pc_key=None): """ Remove received checkpoints up to `till_3pc_key` if provided, otherwise remove all received checkpoints """ if till_3pc_key is None: self._received_checkpoints.clear() self._logger.info( '{} removing all received checkpoints'.format(self)) return for cp in list(self._received_checkpoints.keys()): if self._is_below_3pc_key(cp, till_3pc_key): self._logger.info( '{} removing received checkpoints: {}'.format(self, cp)) del self._received_checkpoints[cp] def _reset_checkpoints(self): # That function most probably redundant in PBFT approach, # because according to paper, checkpoints cleared only when next stabilized. # Avoid using it while implement other services. self._data.checkpoints.clear() self._data.checkpoints.append(self._data.initial_checkpoint) def __str__(self) -> str: return "{} - checkpoint_service".format(self._data.name) def discard(self, msg, reason, sender): self._logger.trace("{} discard message {} from {} " "with the reason: {}".format( self, msg, sender, reason)) def _have_own_checkpoint(self, key: CheckpointKey) -> bool: own_checkpoints = self._data.checkpoints.irange_key( min_key=key.pp_seq_no, max_key=key.pp_seq_no) return any(cp.viewNo == key.view_no and cp.digest == key.digest for cp in own_checkpoints) def _have_quorum_on_received_checkpoint(self, key: CheckpointKey) -> bool: votes = self._received_checkpoints[key] return self._data.quorums.checkpoint.is_reached(len(votes)) def _unknown_stabilized_checkpoints(self) -> List[CheckpointKey]: return [ key for key in self._received_checkpoints if self._have_quorum_on_received_checkpoint(key) and not self._have_own_checkpoint(key) and not self._is_below_3pc_key(key, self.last_ordered_3pc) ] @staticmethod def _is_below_3pc_key(cp: CheckpointKey, key: Tuple[int, int]) -> bool: return compare_3PC_keys((cp.view_no, cp.pp_seq_no), key) >= 0 @staticmethod def _checkpoint_key(checkpoint: Checkpoint) -> CheckpointKey: return CheckpointService.CheckpointKey(view_no=checkpoint.viewNo, pp_seq_no=checkpoint.seqNoEnd, digest=checkpoint.digest) @staticmethod def _audit_seq_no_from_3pc_key(audit_ledger: Ledger, view_no: int, pp_seq_no: int) -> int: # TODO: Should we put it into some common code? seq_no = audit_ledger.size while seq_no > 0: txn = audit_ledger.getBySeqNo(seq_no) txn_data = get_payload_data(txn) audit_view_no = txn_data[AUDIT_TXN_VIEW_NO] audit_pp_seq_no = txn_data[AUDIT_TXN_PP_SEQ_NO] if audit_view_no == view_no and audit_pp_seq_no == pp_seq_no: break seq_no -= 1 return seq_no def _audit_txn_root_hash(self, view_no: int, pp_seq_no: int) -> Optional[str]: audit_ledger = self._db_manager.get_ledger(AUDIT_LEDGER_ID) # TODO: Should we remove view_no at some point? seq_no = self._audit_seq_no_from_3pc_key(audit_ledger, view_no, pp_seq_no) # TODO: What should we do if txn not found or audit ledger is empty? if seq_no == 0: return None root_hash = audit_ledger.tree.merkle_tree_hash(0, seq_no) return audit_ledger.hashToStr(root_hash) def process_new_view_accepted(self, msg: NewViewAccepted): # 1. update shared data cp = msg.checkpoint if cp not in self._data.checkpoints: self._data.checkpoints.append(cp) self._mark_checkpoint_stable(cp.seqNoEnd) self.set_watermarks(low_watermark=cp.seqNoEnd) # 2. send NewViewCheckpointsApplied self._bus.send( NewViewCheckpointsApplied(view_no=msg.view_no, view_changes=msg.view_changes, checkpoint=msg.checkpoint, batches=msg.batches)) return PROCESS, None
class StashingRouter(Router): Handler = Callable[..., Optional[Tuple[int, str]]] def __init__(self, limit: int, buses: List[Router], unstash_handler: Callable = None): super().__init__() self._limit = limit self._logger = getlogger() self._queues = {} # type: Dict[int, StashingQueue] # TODO: This call has been added to saving the old message order in the list. # This is a replica's method that moves the message to the inBox, rather than # calling the handler immediately, as the default router does. self._unstash_handler = unstash_handler self._subscriptions = Subscription() self._buses = buses def set_sorted_stasher(self, code: int, key: Callable): self._queues[code] = SortedStash(self._limit, key) def subscribe(self, message_type: Type, handler: Handler) -> Router.SubscriptionID: # TODO: subscribe to one bus only for bus in self._buses: self._subscriptions.subscribe(bus, message_type, partial(self._process, handler)) return super().subscribe(message_type, handler) def unsubscribe_from_all(self): self._subscriptions.unsubscribe_all() def process_all_stashed(self, code: Optional[int] = None): """ Try to process all stashed messages, re-stashing some of them if needed :param code: stash code, None if we need to unstash all """ if code is None: for code in sorted(self._queues.keys()): self.process_all_stashed(code) return queue = self._queues.get(code) if not queue: return data = queue.pop_all() self._logger.info("Unstash {} messages from stash with code {}".format(len(data), code)) for msg_tuple in data: self._resolve_and_process(*msg_tuple) def process_stashed_until_first_restash(self, code: Optional[int] = None): """ Try to process all stashed messages until handler indicates that some message needs to be stashed again (this can be especially useful with sorted stashes). :param code: stash code, None if we need to unstash all """ if code is None: for code in sorted(self._queues.keys()): self.process_stashed_until_first_restash(code) return queue = self._queues.get(code) while queue: msg_tuple = queue.pop() if not self._resolve_and_process(*msg_tuple): break def stash_size(self, code: Optional[int] = None): if code is None: return sum(len(q) for q in self._queues.values()) queue = self._queues.get(code) return len(queue) if queue else 0 def _process(self, handler: Handler, message: Any, *args) -> bool: """ Tries to process message using given handler. Returns True if message was stashed for reprocessing in future, False otherwise. """ result = handler(message, *args) code, reason = result if result else (None, None) # If handler returned either None or PROCESS we assume it successfully processed message # and no further action is needed if not code: return True if code == DISCARD: self.discard(message, args, reason) return True self._stash(code, reason, message, *args) return False def _resolve_and_process(self, message: Any, *args) -> bool: handlers = self.handlers(type(message)) if len(handlers) == 0: raise LogicError("Handler for message {} not found".format(message)) return self._unstash(handlers[0], message, *args) def _unstash(self, handler: Handler, message: Any, *args) -> bool: if self._unstash_handler is None: return self._process(handler, message, *args) else: self._unstash_handler((message, *args)) def _stash(self, code: int, reason: str, message: Any, *args): self._logger.trace("Stashing message {} with metadata {} " "with the reason {}".format(message, args, reason)) queue = self._queues.setdefault(code, UnsortedStash(self._limit)) if not queue.push(message, *args): # TODO: This is actually better be logged on info level with some throttling applied, # however this cries for some generic easy to use solution, which we don't have yet. self._logger.debug("Cannot stash message {} with metadata {} - queue is full".format(message, args)) def discard(self, msg, args, reason): self._logger.trace("Discarded message {} with metadata {} " "with the reason {}".format(msg, args, reason))
class ViewChangeService: def __init__(self, data: ConsensusSharedData, timer: TimerService, bus: InternalBus, network: ExternalBus, stasher: StashingRouter, primaries_selector: PrimariesSelector): self._config = getConfig() self._logger = getlogger() self._data = data self._new_view_builder = NewViewBuilder(self._data) self._timer = timer self._bus = bus self._network = network self._router = stasher # Last successful viewNo. # In some cases view_change process can be uncompleted in time. # In that case we want to know, which viewNo was successful (last completed view_change) self.last_completed_view_no = self._data.view_no self._resend_inst_change_timer = RepeatingTimer( self._timer, self._config.NEW_VIEW_TIMEOUT, partial(self._propose_view_change_not_complete_in_time), active=False) self._old_prepared = {} # type: Dict[int, BatchID] self._old_preprepared = {} # type: Dict[int, List[BatchID]] self._stashed_vc_msgs = {} # type: Dict[int, int] self._primaries_selector = primaries_selector self._subscription = Subscription() self._subscription.subscribe(self._router, ViewChange, self.process_view_change_message) self._subscription.subscribe(self._router, ViewChangeAck, self.process_view_change_ack_message) self._subscription.subscribe(self._router, NewView, self.process_new_view_message) self._subscription.subscribe(self._bus, NeedViewChange, self.process_need_view_change) def cleanup(self): self._subscription.unsubscribe_all() def __repr__(self): return self._data.name @property def view_change_votes(self): return self._data.view_change_votes def process_need_view_change(self, msg: NeedViewChange): self._logger.info("{} processing {}".format(self, msg)) # 1. calculate new viewno view_no = msg.view_no if view_no is None: view_no = self._data.view_no + 1 # 2. Do cleanup before new view change starts self._clean_on_view_change_start() # 3. Update shared data self._data.view_no = view_no self._data.waiting_for_new_view = True self._data.primaries = self._primaries_selector.select_primaries( view_no=self._data.view_no) for i, primary_name in enumerate(self._data.primaries): self._logger.display( "{} selected primary {} for instance {} (view {})".format( PRIMARY_SELECTION_PREFIX, primary_name, i, self._data.view_no), extra={ "cli": "ANNOUNCE", "tags": ["node-election"] }) old_primary = self._data.primary_name self._data.primary_name = generateName( self._data.primaries[self._data.inst_id], self._data.inst_id) if not self._data.is_master: return if old_primary and self._data.primary_name == old_primary: self._logger.info("Selected master primary is the same with the " "current master primary (new_view {}). " "Propose a new view {}".format( self._data.view_no, self._data.view_no + 1)) self._propose_view_change(Suspicions.INCORRECT_NEW_PRIMARY.code) # 4. Build ViewChange message vc = self._build_view_change_msg() # 5. Send ViewChangeStarted via internal bus to update other services self._logger.info("{} sending {}".format(self, vc)) self._bus.send(ViewChangeStarted(view_no=self._data.view_no)) # 6. Send ViewChange msg to other nodes (via external bus) self._network.send(vc) self.view_change_votes.add_view_change(vc, self._data.name) # 7. Unstash messages for view change self._router.process_all_stashed(STASH_WAITING_VIEW_CHANGE) self._stashed_vc_msgs.clear() # 8. Restart instance change timer self._resend_inst_change_timer.stop() self._resend_inst_change_timer.start() def _clean_on_view_change_start(self): self._clear_old_batches(self._old_prepared) self._clear_old_batches(self._old_preprepared) self.view_change_votes.clear() self._data.new_view = None def _clear_old_batches(self, batches: Dict[int, Any]): for pp_seq_no in list(batches.keys()): if pp_seq_no <= self._data.stable_checkpoint: del batches[pp_seq_no] def _build_view_change_msg(self): for batch_id in self._data.prepared: self._old_prepared[batch_id.pp_seq_no] = batch_id prepared = sorted(list(self._old_prepared.values())) for new_bid in self._data.preprepared: pretenders = self._old_preprepared.get(new_bid.pp_seq_no, []) pretenders = [ bid for bid in pretenders if bid.pp_digest != new_bid.pp_digest ] pretenders.append(new_bid) self._old_preprepared[new_bid.pp_seq_no] = pretenders preprepared = sorted( [bid for bids in self._old_preprepared.values() for bid in bids]) return ViewChange(viewNo=self._data.view_no, stableCheckpoint=self._data.stable_checkpoint, prepared=prepared, preprepared=preprepared, checkpoints=list(self._data.checkpoints)) def process_view_change_message(self, msg: ViewChange, frm: str): result = self._validate(msg, frm) if result == STASH_WAITING_VIEW_CHANGE: self._stashed_vc_msgs.setdefault(msg.viewNo, 0) self._stashed_vc_msgs[msg.viewNo] += 1 if self._data.quorums.view_change.is_reached(self._stashed_vc_msgs[msg.viewNo]) and \ not self._data.waiting_for_new_view: self._bus.send(StartViewChange(msg.viewNo)) if result != PROCESS: return result, None self._logger.info("{} processing {} from {}".format(self, msg, frm)) self.view_change_votes.add_view_change(msg, frm) vca = ViewChangeAck(viewNo=msg.viewNo, name=getNodeName(frm), digest=view_change_digest(msg)) self.view_change_votes.add_view_change_ack( vca, getNodeName(self._data.name)) if self._data.is_primary: self._send_new_view_if_needed() return PROCESS, None primary_node_name = getNodeName(self._data.primary_name) self._logger.info("{} sending {}".format(self, vca)) self._network.send(vca, [primary_node_name]) self._finish_view_change_if_needed() return PROCESS, None def process_view_change_ack_message(self, msg: ViewChangeAck, frm: str): result = self._validate(msg, frm) if result != PROCESS: return result, None self._logger.info("{} processing {} from {}".format(self, msg, frm)) if not self._data.is_primary: return PROCESS, None self.view_change_votes.add_view_change_ack(msg, frm) self._send_new_view_if_needed() return PROCESS, None def process_new_view_message(self, msg: NewView, frm: str): result = self._validate(msg, frm) if result != PROCESS: return result, None self._logger.info("{} processing {} from {}".format(self, msg, frm)) if frm != self._data.primary_name: self._logger.info( "{} Received NewView {} for view {} from non-primary {}; expected primary {}" .format(self._data.name, msg, self._data.view_no, frm, self._data.primary_name)) return DISCARD, "New View from non-Primary" self._data.new_view = msg self._finish_view_change_if_needed() return PROCESS, None def _validate(self, msg: Union[ViewChange, ViewChangeAck, NewView], frm: str) -> int: # TODO: Proper validation if not self._data.is_master: return DISCARD if msg.viewNo < self._data.view_no: return DISCARD if msg.viewNo == self._data.view_no and not self._data.waiting_for_new_view: return DISCARD if msg.viewNo > self._data.view_no: return STASH_WAITING_VIEW_CHANGE return PROCESS def _send_new_view_if_needed(self): confirmed_votes = self.view_change_votes.confirmed_votes if not self._data.quorums.view_change.is_reached(len(confirmed_votes)): return view_changes = [ self.view_change_votes.get_view_change(*v) for v in confirmed_votes ] cp = self._new_view_builder.calc_checkpoint(view_changes) if cp is None: return batches = self._new_view_builder.calc_batches(cp, view_changes) if batches is None: return if cp not in self._data.checkpoints: return nv = NewView(viewNo=self._data.view_no, viewChanges=sorted(confirmed_votes, key=itemgetter(0)), checkpoint=cp, batches=batches) self._logger.info("{} sending {}".format(self, nv)) self._network.send(nv) self._data.new_view = nv self._finish_view_change() def _finish_view_change_if_needed(self): if self._data.new_view is None: return view_changes = [] for name, vc_digest in self._data.new_view.viewChanges: vc = self.view_change_votes.get_view_change(name, vc_digest) # We don't have needed ViewChange, so we cannot validate NewView if vc is None: self._request_view_change_message((name, vc_digest)) return view_changes.append(vc) cp = self._new_view_builder.calc_checkpoint(view_changes) if cp is None or cp != self._data.new_view.checkpoint: # New primary is malicious self._logger.info( "{} Received invalid NewView {} for view {}: expected checkpoint {}" .format(self._data.name, self._data.new_view, self._data.view_no, cp)) self._propose_view_change( Suspicions.NEW_VIEW_INVALID_CHECKPOINTS.code) return batches = self._new_view_builder.calc_batches(cp, view_changes) if batches != self._data.new_view.batches: # New primary is malicious self._logger.info( "{} Received invalid NewView {} for view {}: expected batches {}" .format(self._data.name, self._data.new_view, self._data.view_no, batches)) self._propose_view_change(Suspicions.NEW_VIEW_INVALID_BATCHES.code) return self._finish_view_change() def _finish_view_change(self): self._logger.info( "{} finished view change to view {}. Primaries: {}".format( self._data.name, self._data.view_no, self._data.primaries)) # Update shared data self._data.waiting_for_new_view = False self._data.prev_view_prepare_cert = self._data.new_view.batches[-1].pp_seq_no \ if self._data.new_view.batches else 0 # Cancel View Change timeout task self._resend_inst_change_timer.stop() # send message to other services self._bus.send( NewViewAccepted(view_no=self._data.new_view.viewNo, view_changes=self._data.new_view.viewChanges, checkpoint=self._data.new_view.checkpoint, batches=self._data.new_view.batches)) self.last_completed_view_no = self._data.view_no def _propose_view_change_not_complete_in_time(self): self._propose_view_change(Suspicions.INSTANCE_CHANGE_TIMEOUT.code) if self._data.new_view is None: self._request_new_view_message(self._data.view_no) def _propose_view_change(self, suspision_code): proposed_view_no = self._data.view_no # TODO: For some reason not incrementing view_no in most cases leads to lots of failing/flaky tests # if suspicion == Suspicions.INSTANCE_CHANGE_TIMEOUT or not self.view_change_in_progress: if suspision_code != Suspicions.STATE_SIGS_ARE_NOT_UPDATED or not self._data.waiting_for_new_view: proposed_view_no += 1 self._logger.info( "{} proposing a view change to {} with code {}".format( self, proposed_view_no, suspision_code)) msg = InstanceChange(proposed_view_no, suspision_code) self._network.send(msg) def _request_new_view_message(self, view_no): self._bus.send( MissingMessage(msg_type=NEW_VIEW, key=view_no, inst_id=self._data.inst_id, dst=[getNodeName(self._data.primary_name)], stash_data=None)) def _request_view_change_message(self, key): self._bus.send( MissingMessage(msg_type=VIEW_CHANGE, key=key, inst_id=self._data.inst_id, dst=None, stash_data=None))
class CheckpointService: STASHED_CHECKPOINTS_BEFORE_CATCHUP = 1 def __init__( self, data: ConsensusSharedData, bus: InternalBus, network: ExternalBus, stasher: StashingRouter, db_manager: DatabaseManager, metrics: MetricsCollector = NullMetricsCollector(), ): self._data = data self._bus = bus self._network = network self._checkpoint_state = SortedDict(lambda k: k[1]) self._stasher = stasher self._subscription = Subscription() self._validator = CheckpointMsgValidator(self._data) self._db_manager = db_manager self.metrics = metrics # Stashed checkpoints for each view. The key of the outermost # dictionary is the view_no, value being a dictionary with key as the # range of the checkpoint and its value again being a mapping between # senders and their sent checkpoint # Dict[view_no, Dict[(seqNoStart, seqNoEnd), Dict[sender, Checkpoint]]] self._stashed_recvd_checkpoints = {} self._config = getConfig() self._logger = getlogger() self._subscription.subscribe(stasher, Checkpoint, self.process_checkpoint) self._subscription.subscribe(bus, Ordered, self.process_ordered) self._subscription.subscribe(bus, BackupSetupLastOrdered, self.process_backup_setup_last_ordered) self._subscription.subscribe(bus, NewViewAccepted, self.process_new_view_accepted) def cleanup(self): self._subscription.unsubscribe_all() @property def view_no(self): return self._data.view_no @property def is_master(self): return self._data.is_master @property def last_ordered_3pc(self): return self._data.last_ordered_3pc @measure_consensus_time(MetricsName.PROCESS_CHECKPOINT_TIME, MetricsName.BACKUP_PROCESS_CHECKPOINT_TIME) def process_checkpoint(self, msg: Checkpoint, sender: str) -> (bool, str): """ Process checkpoint messages :return: whether processed (True) or stashed (False) """ if msg.instId != self._data.inst_id: return None, None self._logger.info('{} processing checkpoint {} from {}'.format( self, msg, sender)) result, reason = self._validator.validate(msg) if result == PROCESS: self._do_process_checkpoint(msg, sender) return result, reason def _do_process_checkpoint(self, msg: Checkpoint, sender: str) -> bool: """ Process checkpoint messages :return: whether processed (True) or stashed (False) """ seqNoEnd = msg.seqNoEnd seqNoStart = msg.seqNoStart key = (seqNoStart, seqNoEnd) if key not in self._checkpoint_state or not self._checkpoint_state[ key].digest: self._stash_checkpoint(msg, sender) self._remove_stashed_checkpoints(self.last_ordered_3pc) self._start_catchup_if_needed() return False checkpoint_state = self._checkpoint_state[key] # Raise the error only if master since only master's last # ordered 3PC is communicated during view change if self.is_master and checkpoint_state.digest != msg.digest: self._logger.warning("{} received an incorrect digest {} for " "checkpoint {} from {}".format( self, msg.digest, key, sender)) return True checkpoint_state.receivedDigests[sender] = msg.digest self._check_if_checkpoint_stable(key) return True def process_backup_setup_last_ordered(self, msg: BackupSetupLastOrdered): if msg.inst_id != self._data.inst_id: return self.update_watermark_from_3pc() def process_ordered(self, ordered: Ordered): if ordered.instId != self._data.inst_id: return for batch_id in reversed(self._data.preprepared): if batch_id.pp_seq_no == ordered.ppSeqNo: self._add_to_checkpoint(batch_id.pp_seq_no, batch_id.pp_digest, ordered.ledgerId, batch_id.view_no, ordered.auditTxnRootHash) return raise LogicError( "CheckpointService | Can't process Ordered msg because " "ppSeqNo {} not in preprepared".format(ordered.ppSeqNo)) def _start_catchup_if_needed(self): stashed_checkpoint_ends = self._stashed_checkpoints_with_quorum() lag_in_checkpoints = len(stashed_checkpoint_ends) if self._checkpoint_state: (s, e) = firstKey(self._checkpoint_state) # If the first stored own checkpoint has a not aligned lower bound # (this means that it was started after a catch-up), is complete # and there is a quorumed stashed checkpoint from other replicas # with the same end then don't include this stashed checkpoint # into the lag if s % self._config.CHK_FREQ != 0 \ and self._checkpoint_state[(s, e)].seqNo == e \ and e in stashed_checkpoint_ends: lag_in_checkpoints -= 1 is_stashed_enough = \ lag_in_checkpoints > self.STASHED_CHECKPOINTS_BEFORE_CATCHUP if not is_stashed_enough: return if self.is_master: self._logger.display( '{} has lagged for {} checkpoints so updating watermarks to {}' .format(self, lag_in_checkpoints, stashed_checkpoint_ends[-1])) self.set_watermarks(low_watermark=stashed_checkpoint_ends[-1]) if not self._data.is_primary: self._logger.display( '{} has lagged for {} checkpoints so the catchup procedure starts' .format(self, lag_in_checkpoints)) self._bus.send(NeedMasterCatchup()) else: self._logger.info( '{} has lagged for {} checkpoints so adjust last_ordered_3pc to {}, ' 'shift watermarks and clean collections'.format( self, lag_in_checkpoints, stashed_checkpoint_ends[-1])) # Adjust last_ordered_3pc, shift watermarks, clean operational # collections and process stashed messages which now fit between # watermarks key_3pc = (self.view_no, stashed_checkpoint_ends[-1]) self._bus.send( NeedBackupCatchup(inst_id=self._data.inst_id, caught_up_till_3pc=key_3pc)) self.caught_up_till_3pc(key_3pc) def gc_before_new_view(self): self._reset_checkpoints() self._remove_stashed_checkpoints(till_3pc_key=(self.view_no, 0)) def caught_up_till_3pc(self, caught_up_till_3pc): self._reset_checkpoints() self._remove_stashed_checkpoints(till_3pc_key=caught_up_till_3pc) self.update_watermark_from_3pc() def catchup_clear_for_backup(self): self._reset_checkpoints() self._remove_stashed_checkpoints() self.set_watermarks(low_watermark=0, high_watermark=sys.maxsize) def _add_to_checkpoint(self, ppSeqNo, digest, ledger_id, view_no, audit_txn_root_hash): for (s, e) in self._checkpoint_state.keys(): if s <= ppSeqNo <= e: state = self._checkpoint_state[s, e] # type: CheckpointState state.digests.append(digest) state = updateNamedTuple(state, seqNo=ppSeqNo) self._checkpoint_state[s, e] = state break else: s, e = ppSeqNo, math.ceil( ppSeqNo / self._config.CHK_FREQ) * self._config.CHK_FREQ self._logger.debug("{} adding new checkpoint state for {}".format( self, (s, e))) state = CheckpointState(ppSeqNo, [ digest, ], None, {}, False) self._checkpoint_state[s, e] = state if state.seqNo == e: if len(state.digests) == self._config.CHK_FREQ: self._do_checkpoint(state, s, e, ledger_id, view_no, audit_txn_root_hash) self._process_stashed_checkpoints((s, e), view_no) @measure_consensus_time(MetricsName.SEND_CHECKPOINT_TIME, MetricsName.BACKUP_SEND_CHECKPOINT_TIME) def _do_checkpoint(self, state, s, e, ledger_id, view_no, audit_txn_root_hash): # TODO CheckpointState/Checkpoint is not a namedtuple anymore # 1. check if updateNamedTuple works for the new message type # 2. choose another name # TODO: This is hack of hacks, should be removed when refactoring is complete if not self.is_master and audit_txn_root_hash is None: audit_txn_root_hash = "7RJ5bkAKRy2CCvarRij2jiHC16SVPjHcrpVdNsboiQGv" state = updateNamedTuple(state, digest=audit_txn_root_hash, digests=[]) self._checkpoint_state[s, e] = state self._logger.info( "{} sending Checkpoint {} view {} checkpointState digest {}. Ledger {} " "txn root hash {}. Committed state root hash {} Uncommitted state root hash {}" .format( self, (s, e), view_no, state.digest, ledger_id, self._db_manager.get_txn_root_hash(ledger_id), self._db_manager.get_state_root_hash(ledger_id, committed=True), self._db_manager.get_state_root_hash(ledger_id, committed=False))) checkpoint = Checkpoint(self._data.inst_id, view_no, s, e, state.digest) self._network.send(checkpoint) self._data.checkpoints.append(checkpoint) def _mark_checkpoint_stable(self, seqNo): previousCheckpoints = [] for (s, e), state in self._checkpoint_state.items(): if e == seqNo: # TODO CheckpointState/Checkpoint is not a namedtuple anymore # 1. check if updateNamedTuple works for the new message type # 2. choose another name state = updateNamedTuple(state, isStable=True) self._checkpoint_state[s, e] = state self._set_stable_checkpoint(e) break else: previousCheckpoints.append((s, e)) else: self._logger.debug("{} could not find {} in checkpoints".format( self, seqNo)) return self.set_watermarks(low_watermark=seqNo) for k in previousCheckpoints: self._logger.trace("{} removing previous checkpoint {}".format( self, k)) self._checkpoint_state.pop(k) self._remove_stashed_checkpoints(till_3pc_key=(self.view_no, seqNo)) self._bus.send( CheckpointStabilized(self._data.inst_id, (self.view_no, seqNo))) self._logger.info("{} marked stable checkpoint {}".format( self, (s, e))) def _check_if_checkpoint_stable(self, key: Tuple[int, int]): ckState = self._checkpoint_state[key] if self._data.quorums.checkpoint.is_reached( len(ckState.receivedDigests)): self._mark_checkpoint_stable(ckState.seqNo) return True else: self._logger.debug('{} has state.receivedDigests as {}'.format( self, ckState.receivedDigests.keys())) return False def _stash_checkpoint(self, ck: Checkpoint, sender: str): self._logger.debug('{} stashing {} from {}'.format(self, ck, sender)) seqNoStart, seqNoEnd = ck.seqNoStart, ck.seqNoEnd if ck.viewNo not in self._stashed_recvd_checkpoints: self._stashed_recvd_checkpoints[ck.viewNo] = {} stashed_for_view = self._stashed_recvd_checkpoints[ck.viewNo] if (seqNoStart, seqNoEnd) not in stashed_for_view: stashed_for_view[seqNoStart, seqNoEnd] = {} stashed_for_view[seqNoStart, seqNoEnd][sender] = ck def _stashed_checkpoints_with_quorum(self): end_pp_seq_numbers = [] quorum = self._data.quorums.checkpoint for (_, seq_no_end), senders in self._stashed_recvd_checkpoints.get( self.view_no, {}).items(): if quorum.is_reached(len(senders)): end_pp_seq_numbers.append(seq_no_end) return sorted(end_pp_seq_numbers) def _process_stashed_checkpoints(self, key, view_no): # Remove all checkpoints from previous views if any self._remove_stashed_checkpoints(till_3pc_key=(self.view_no, 0)) if key not in self._stashed_recvd_checkpoints.get(view_no, {}): self._logger.trace("{} have no stashed checkpoints for {}") return # Get a snapshot of all the senders of stashed checkpoints for `key` senders = list(self._stashed_recvd_checkpoints[view_no][key].keys()) total_processed = 0 consumed = 0 for sender in senders: # Check if the checkpoint from `sender` is still in # `stashed_recvd_checkpoints` because it might be removed from there # in case own checkpoint was stabilized when we were processing # stashed checkpoints from previous senders in this loop if view_no in self._stashed_recvd_checkpoints \ and key in self._stashed_recvd_checkpoints[view_no] \ and sender in self._stashed_recvd_checkpoints[view_no][key]: if self.process_checkpoint( self._stashed_recvd_checkpoints[view_no][key].pop( sender), sender): consumed += 1 # Note that if `process_checkpoint` returned False then the # checkpoint from `sender` was re-stashed back to # `stashed_recvd_checkpoints` total_processed += 1 # If we have consumed stashed checkpoints for `key` from all the # senders then remove entries which have become empty if view_no in self._stashed_recvd_checkpoints \ and key in self._stashed_recvd_checkpoints[view_no] \ and len(self._stashed_recvd_checkpoints[view_no][key]) == 0: del self._stashed_recvd_checkpoints[view_no][key] if len(self._stashed_recvd_checkpoints[view_no]) == 0: del self._stashed_recvd_checkpoints[view_no] restashed = total_processed - consumed self._logger.info('{} processed {} stashed checkpoints for {}, ' '{} of them were stashed again'.format( self, total_processed, key, restashed)) return total_processed def reset_watermarks_before_new_view(self): # Reset any previous view watermarks since for view change to # successfully complete, the node must have reached the same state # as other nodes self.set_watermarks(low_watermark=0) def should_reset_watermarks_before_new_view(self): if self.view_no <= 0: return False if self.last_ordered_3pc[ 0] == self.view_no and self.last_ordered_3pc[1] > 0: return False return True def set_watermarks(self, low_watermark: int, high_watermark: int = None): self._data.low_watermark = low_watermark self._data.high_watermark = self._data.low_watermark + self._config.LOG_SIZE \ if high_watermark is None else \ high_watermark self._logger.info('{} set watermarks as {} {}'.format( self, self._data.low_watermark, self._data.high_watermark)) self._stasher.process_all_stashed(STASH_WATERMARKS) def update_watermark_from_3pc(self): last_ordered_3pc = self.last_ordered_3pc if (last_ordered_3pc is not None) and (last_ordered_3pc[0] == self.view_no): self._logger.info( "update_watermark_from_3pc to {}".format(last_ordered_3pc)) self.set_watermarks(last_ordered_3pc[1]) else: self._logger.info( "try to update_watermark_from_3pc but last_ordered_3pc is None" ) def _remove_stashed_checkpoints(self, till_3pc_key=None): """ Remove stashed received checkpoints up to `till_3pc_key` if provided, otherwise remove all stashed received checkpoints """ if till_3pc_key is None: self._stashed_recvd_checkpoints.clear() self._logger.info( '{} removing all stashed checkpoints'.format(self)) return for view_no in list(self._stashed_recvd_checkpoints.keys()): if view_no < till_3pc_key[0]: self._logger.info( '{} removing stashed checkpoints for view {}'.format( self, view_no)) del self._stashed_recvd_checkpoints[view_no] elif view_no == till_3pc_key[0]: for (s, e) in list( self._stashed_recvd_checkpoints[view_no].keys()): if e <= till_3pc_key[1]: self._logger.info( '{} removing stashed checkpoints: ' 'viewNo={}, seqNoStart={}, seqNoEnd={}'.format( self, view_no, s, e)) del self._stashed_recvd_checkpoints[view_no][(s, e)] if len(self._stashed_recvd_checkpoints[view_no]) == 0: del self._stashed_recvd_checkpoints[view_no] def _reset_checkpoints(self): # That function most probably redundant in PBFT approach, # because according to paper, checkpoints cleared only when next stabilized. # Avoid using it while implement other services. self._checkpoint_state.clear() self._data.checkpoints.clear() # TODO: change to = 1 in ViewChangeService integration. self._data.stable_checkpoint = 0 def _set_stable_checkpoint(self, end_seq_no): if not list(self._data.checkpoints.irange_key(end_seq_no, end_seq_no)): raise LogicError('Stable checkpoint must be in checkpoints') self._data.stable_checkpoint = end_seq_no self._data.checkpoints = \ SortedListWithKey([c for c in self._data.checkpoints if c.seqNoEnd >= end_seq_no], key=lambda checkpoint: checkpoint.seqNoEnd) def __str__(self) -> str: return "{} - checkpoint_service".format(self._data.name) # TODO: move to OrderingService as a handler for Cleanup messages # def _clear_batch_till_seq_no(self, seq_no): # self._data.preprepared = [pp for pp in self._data.preprepared if pp.ppSeqNo >= seq_no] # self._data.prepared = [p for p in self._data.prepared if p.ppSeqNo >= seq_no] def discard(self, msg, reason, sender): self._logger.trace("{} discard message {} from {} " "with the reason: {}".format( self, msg, sender, reason)) def process_new_view_accepted(self, msg: NewViewAccepted): # 1. update shared data cp = msg.checkpoint if cp not in self._data.checkpoints: self._data.checkpoints.append(cp) self._set_stable_checkpoint(cp.seqNoEnd) self.set_watermarks(low_watermark=cp.seqNoEnd) # 2. send NewViewCheckpointsApplied self._bus.send( NewViewCheckpointsApplied(view_no=msg.view_no, view_changes=msg.view_changes, checkpoint=msg.checkpoint, batches=msg.batches)) return PROCESS, None
class ViewChangeTriggerService: def __init__(self, data: ConsensusSharedData, timer: TimerService, bus: InternalBus, network: ExternalBus, db_manager: DatabaseManager, stasher: StashingRouter, is_master_degraded: Callable[[], bool], metrics: MetricsCollector = NullMetricsCollector()): self._data = data self._timer = timer self._bus = bus self._network = network self._stasher = stasher self._is_master_degraded = is_master_degraded self.metrics = metrics self._config = getConfig() self._instance_changes = \ InstanceChangeProvider(outdated_ic_interval=self._config.OUTDATED_INSTANCE_CHANGES_CHECK_INTERVAL, node_status_db=db_manager.get_store(NODE_STATUS_DB_LABEL), time_provider=timer.get_current_time) self._subscription = Subscription() self._subscription.subscribe(bus, VoteForViewChange, self.process_vote_for_view_change) self._subscription.subscribe(bus, NewViewAccepted, self.process_new_view_accepted) self._subscription.subscribe(stasher, InstanceChange, self.process_instance_change) def cleanup(self): self._subscription.unsubscribe_all() @property def name(self): return replica_name_to_node_name(self._data.name) def __repr__(self): return self.name def process_vote_for_view_change(self, msg: VoteForViewChange): proposed_view_no = self._data.view_no # TODO: Some time ago it was proposed that view_no should not be increased during proposal # if view change is already in progress, unless suspicion code is "view change is taking too long". # Idea was to improve stability of view change triggering, however for some reason this change lead # to lots of failing/flaky tests. This still needs to be investigated. # if suspicion == Suspicions.INSTANCE_CHANGE_TIMEOUT or not self.view_change_in_progress: if msg.suspicion != Suspicions.STATE_SIGS_ARE_NOT_UPDATED or not self._data.waiting_for_new_view: proposed_view_no += 1 self._send_instance_change(proposed_view_no, msg.suspicion) def process_instance_change(self, msg: InstanceChange, frm: str): frm = replica_name_to_node_name(frm) # TODO: Do we really need this? if frm not in self._network.connecteds: return DISCARD, "instance change request: {} from {} which is not in connected list: {}".\ format(msg, frm, self._network.connecteds) if not self._data.is_participating: return STASH_CATCH_UP, CATCHING_UP logger.info("{} received instance change request: {} from {}".format(self, msg, frm)) if msg.viewNo <= self._data.view_no: return DISCARD, "instance change request with view no {} which is not more than its view no {}".\ format(msg.viewNo, self._data.view_no) # Record instance changes for views but send instance change # only when found master to be degraded. if quorum of view changes # found then change view even if master not degraded self._on_verified_instance_change_msg(msg, frm) if self._instance_changes.has_inst_chng_from(msg.viewNo, self.name): logger.info("{} received instance change message {} " "but has already sent an instance change message".format(self, msg)) elif not self._is_master_degraded(): logger.info("{} received instance change message {} " "but did not find the master to be slow".format(self, msg)) else: logger.display("{}{} found master degraded after " "receiving instance change message from {}".format(VIEW_CHANGE_PREFIX, self, frm)) self._send_instance_change(msg.viewNo, Suspicions.PRIMARY_DEGRADED) def process_new_view_accepted(self, msg: NewViewAccepted): self._instance_changes.remove_view(self._data.view_no) def _send_instance_change(self, view_no: int, suspicion: Suspicion): logger.info("{}{} sending an instance change with view_no {} since {}". format(VIEW_CHANGE_PREFIX, self, view_no, suspicion.reason)) msg = InstanceChange(view_no, suspicion.code) self._network.send(msg) # record instance change vote for self and try to change the view if quorum is reached self._on_verified_instance_change_msg(msg, self.name) def _on_verified_instance_change_msg(self, msg: InstanceChange, frm: str): view_no = msg.viewNo if not self._instance_changes.has_inst_chng_from(view_no, frm): self._instance_changes.add_vote(msg, frm) if view_no > self._data.view_no: self._try_start_view_change_by_instance_change(view_no) def _try_start_view_change_by_instance_change(self, proposed_view_no: int) -> bool: # TODO: Need to handle skewed distributions which can arise due to # malicious nodes sending messages early on can, why_not = self._can_view_change(proposed_view_no) if can: logger.display("{}{} initiating a view change to {} from {}". format(VIEW_CHANGE_PREFIX, self, proposed_view_no, self._data.view_no)) self._bus.send(NodeNeedViewChange(view_no=proposed_view_no)) else: logger.info(why_not) return can def _can_view_change(self, proposed_view_no: int) -> (bool, str): quorum = self._data.quorums.view_change.value if not self._instance_changes.has_quorum(proposed_view_no, quorum): return False, '{} has no quorum for view {}'.format(self, proposed_view_no) if not proposed_view_no > self._data.view_no: return False, '{} is in higher view more than {}'.format(self, proposed_view_no) return True, ''
class PrimaryConnectionMonitorService: def __init__(self, data: ConsensusSharedData, timer: TimerService, bus: InternalBus, network: ExternalBus, metrics: MetricsCollector = NullMetricsCollector()): self._data = data self._timer = timer self._bus = bus self._network = network self.metrics = metrics self._config = getConfig() self._primary_disconnection_time = timer.get_current_time( ) # type: Optional[float] self._propose_view_change_timer = RepeatingTimer( timer=timer, interval=self._config.NEW_VIEW_TIMEOUT, callback=self._propose_view_change_if_needed, active=False) self._subscription = Subscription() self._subscription.subscribe(network, ExternalBus.Connected, self.process_connected) self._subscription.subscribe(network, ExternalBus.Disconnected, self.process_disconnected) self._subscription.subscribe(bus, PrimarySelected, self.process_primary_selected) self._subscription.subscribe(bus, NodeStatusUpdated, self.process_node_status_updated) if self._data.is_master: self._schedule_primary_connection_check( delay=self._config.INITIAL_PROPOSE_VIEW_CHANGE_TIMEOUT) def __str__(self): return self._data.name def cleanup(self): self._subscription.unsubscribe_all() self._propose_view_change_timer.stop() def process_connected(self, msg: ExternalBus.Connected, frm: str): if frm == replica_name_to_node_name(self._data.primary_name): self._primary_connected() def process_disconnected(self, msg: ExternalBus.Disconnected, frm: str): if frm == replica_name_to_node_name(self._data.primary_name): self._primary_disconnected() def process_primary_selected(self, msg: PrimarySelected): primary_name = replica_name_to_node_name(self._data.primary_name) primary_connected = self._data.is_primary or primary_name in self._network.connecteds if primary_connected: self._primary_connected() else: self._primary_disconnected() def process_node_status_updated(self, msg: NodeStatusUpdated): # TODO: This was ported from old code, but there is quite high chance # that this functionality is not needed anymore if msg.old_status == Status.starting \ and msg.new_status == Status.started_hungry \ and self._primary_disconnection_time is not None \ and self._data.primary_name is not None: """ Such situation may occur if the pool has come back to reachable consensus but primary is still disconnected, so view change proposal makes sense now. """ self._schedule_primary_connection_check() def _primary_connected(self): self._primary_disconnection_time = None if self._data.is_master: logger.display( '{} restored connection to primary of master'.format(self)) self._timer.cancel(self._check_primary_connection) self._propose_view_change_timer.stop() def _primary_disconnected(self): self._primary_disconnection_time = self._timer.get_current_time() self._bus.send(PrimaryDisconnected(inst_id=self._data.inst_id)) if self._data.is_master: logger.display( '{} lost connection to primary of master'.format(self)) self._schedule_primary_connection_check() def _schedule_primary_connection_check(self, delay: Optional[float] = None): if delay is None: delay = self._config.ToleratePrimaryDisconnection logger.info('{} scheduling primary connection check in {} sec'.format( self, delay)) self._timer.schedule(delay=delay, callback=self._check_primary_connection) def _check_primary_connection(self): if self._primary_disconnection_time is None: logger.info('{} The primary is already connected ' 'so view change will not be proposed'.format(self)) return logger.display( "{} primary has been disconnected for too long".format(self)) if not self._data.is_ready or not self._data.is_synced: logger.info( '{} The node is not ready yet so ' 'view change will not be proposed now, but re-scheduled.'. format(self)) self._schedule_primary_connection_check() return self._propose_view_change() self._propose_view_change_timer.start() def _propose_view_change(self): self._bus.send( VoteForViewChange(suspicion=Suspicions.PRIMARY_DISCONNECTED)) def _propose_view_change_if_needed(self): if self._primary_disconnection_time is not None: self._propose_view_change()
class ViewChangeService: def __init__(self, data: ConsensusSharedData, timer: TimerService, bus: InternalBus, network: ExternalBus, stasher: StashingRouter, primaries_selector: PrimariesSelector): self._config = getConfig() self._data = data self._new_view_builder = NewViewBuilder(self._data) self._timer = timer self._bus = bus self._network = network self._router = stasher # Last successful viewNo. # In some cases view_change process can be uncompleted in time. # In that case we want to know, which viewNo was successful (last completed view_change) self.last_completed_view_no = self._data.view_no self._resend_inst_change_timer = RepeatingTimer( self._timer, self._config.NEW_VIEW_TIMEOUT, self._propose_view_change_not_complete_in_time, active=False) self._old_prepared = {} # type: Dict[int, BatchID] self._old_preprepared = {} # type: Dict[int, List[BatchID]] self._stashed_vc_msgs = {} # type: Dict[int, int] self._primaries_selector = primaries_selector self._subscription = Subscription() self._subscription.subscribe(self._router, ViewChange, self.process_view_change_message) self._subscription.subscribe(self._router, ViewChangeAck, self.process_view_change_ack_message) self._subscription.subscribe(self._router, NewView, self.process_new_view_message) self._subscription.subscribe(self._bus, NeedViewChange, self.process_need_view_change) def cleanup(self): self._subscription.unsubscribe_all() def __repr__(self): return self._data.name @property def view_change_votes(self): return self._data.view_change_votes def process_need_view_change(self, msg: NeedViewChange): logger.info("{} processing {}".format(self, msg)) # 1. calculate new viewno view_no = msg.view_no if view_no is None: view_no = self._data.view_no + 1 # 2. Do cleanup before new view change starts self._clean_on_view_change_start() # 3. Update shared data self._data.view_no = view_no self._data.waiting_for_new_view = True old_primary = self._data.primary_name self._data.primary_name = None if not self._data.is_master: self._data.master_reordered_after_vc = False return # Only the master primary is selected at the beginning of view change as we need to get a NEW_VIEW and do re-ordering on master # Backup primaries will not be selected (and backups will not order) until re-ordering of txns from previous view on master is finished # More precisely, it will be done after the first batch in a new view is committed # This is done so as N and F may change as a result of NODE txns ordered in last view, # so we need a synchronous point of updating N, F, number of replicas and backup primaris # Beginning of view (when the first batch in a view is ordered) is such a point. self._data.primary_name = generateName( self._primaries_selector.select_master_primary(self._data.view_no), self._data.inst_id) if old_primary and self._data.primary_name == old_primary: logger.info("Selected master primary is the same with the " "current master primary (new_view {}). " "Propose a new view {}".format(self._data.view_no, self._data.view_no + 1)) self._propose_view_change(Suspicions.INCORRECT_NEW_PRIMARY) logger.info( "{} started view change to view {}. Expected Master Primary: {}". format(self._data.name, self._data.view_no, self._data.primary_name)) # 4. Build ViewChange message vc = self._build_view_change_msg() # 5. Send ViewChangeStarted via internal bus to update other services logger.info("{} sending {}".format(self, vc)) self._bus.send(ViewChangeStarted(view_no=self._data.view_no)) # 6. Send ViewChange msg to other nodes (via external bus) self._network.send(vc) self.view_change_votes.add_view_change(vc, self._data.name) # 7. Unstash messages for view change self._router.process_all_stashed(STASH_WAITING_VIEW_CHANGE) self._stashed_vc_msgs.clear() # 8. Restart instance change timer self._resend_inst_change_timer.stop() self._resend_inst_change_timer.start() def _clean_on_view_change_start(self): self._clear_old_batches(self._old_prepared) self._clear_old_batches(self._old_preprepared) self.view_change_votes.clear() self._data.new_view_votes.clear() def _clear_old_batches(self, batches: Dict[int, Any]): for pp_seq_no in list(batches.keys()): if pp_seq_no <= self._data.stable_checkpoint: del batches[pp_seq_no] def _build_view_change_msg(self): for batch_id in self._data.prepared: self._old_prepared[batch_id.pp_seq_no] = batch_id prepared = sorted(list(self._old_prepared.values())) for new_bid in self._data.preprepared: pretenders = self._old_preprepared.get(new_bid.pp_seq_no, []) pretenders = [ bid for bid in pretenders if bid.pp_digest != new_bid.pp_digest ] pretenders.append(new_bid) self._old_preprepared[new_bid.pp_seq_no] = pretenders preprepared = sorted( [bid for bids in self._old_preprepared.values() for bid in bids]) return ViewChange(viewNo=self._data.view_no, stableCheckpoint=self._data.stable_checkpoint, prepared=prepared, preprepared=preprepared, checkpoints=list(self._data.checkpoints)) def process_view_change_message(self, msg: ViewChange, frm: str): result, reason = self._validate(msg, frm) if result == STASH_WAITING_VIEW_CHANGE: self._stashed_vc_msgs.setdefault(msg.viewNo, 0) self._stashed_vc_msgs[msg.viewNo] += 1 if self._data.quorums.view_change.is_reached(self._stashed_vc_msgs[msg.viewNo]) and \ not self._data.waiting_for_new_view: self._bus.send(NodeNeedViewChange(msg.viewNo)) if result != PROCESS: return result, reason logger.info("{} processing {} from {}".format(self, msg, frm)) self.view_change_votes.add_view_change(msg, frm) vca = ViewChangeAck(viewNo=msg.viewNo, name=replica_name_to_node_name(frm), digest=view_change_digest(msg)) self.view_change_votes.add_view_change_ack( vca, replica_name_to_node_name(self._data.name)) if self._data.is_primary: self._send_new_view_if_needed() return PROCESS, None primary_node_name = replica_name_to_node_name(self._data.primary_name) logger.info("{} sending {}".format(self, vca)) self._network.send(vca, [primary_node_name]) self._finish_view_change_if_needed() return PROCESS, None def process_view_change_ack_message(self, msg: ViewChangeAck, frm: str): result, reason = self._validate(msg, frm) if result != PROCESS: return result, reason logger.info("{} processing {} from {}".format(self, msg, frm)) if not self._data.is_primary: return PROCESS, None self.view_change_votes.add_view_change_ack(msg, frm) self._send_new_view_if_needed() return PROCESS, None def process_new_view_message(self, msg: NewView, frm: str): result, reason = self._validate(msg, frm) if result != PROCESS: return result, reason logger.info("{} processing {} from {}".format(self, msg, frm)) if frm != self._data.primary_name: logger.warning("Received NEW_VIEW message from non-primary node. " "Selected primaries may differ on other nodes") self._data.new_view_votes.add_new_view(msg, frm) self._finish_view_change_if_needed() return PROCESS, None def _validate(self, msg: Union[ViewChange, ViewChangeAck, NewView], frm: str) -> (int, str): # TODO: Proper validation if not self._data.is_master: return DISCARD, "not master instance" if msg.viewNo < self._data.view_no: return DISCARD, "message has old view {}, current view {}".format( msg.viewNo, self._data.view_no) if msg.viewNo == self._data.view_no and not self._data.waiting_for_new_view: return DISCARD, "message has current view {}, but we already finished view change".format( msg.viewNo) if not self._data.is_participating: return STASH_CATCH_UP, "we're not participating yet" if msg.viewNo > self._data.view_no: return STASH_WAITING_VIEW_CHANGE, "message is from future view {}".format( msg.viewNo) return PROCESS, None def _send_new_view_if_needed(self): confirmed_votes = self.view_change_votes.confirmed_votes if not self._data.quorums.view_change.is_reached(len(confirmed_votes)): logger.debug( "{} can not send NEW_VIEW: no quorum. Has {}, expects {} votes" .format(self._data.name, len(confirmed_votes), self._data.quorums.view_change.value)) return view_changes = [ self.view_change_votes.get_view_change(*v) for v in confirmed_votes ] cp = self._new_view_builder.calc_checkpoint(view_changes) if cp is None: logger.info( "{} can not send NEW_VIEW: can not calculate Checkpoint". format(self._data.name)) return batches = self._new_view_builder.calc_batches(cp, view_changes) if batches is None: logger.info( "{} can not send NEW_VIEW: can not calculate Batches".format( self._data.name)) return if cp not in self._data.checkpoints: logger.info( "{} can not send NEW_VIEW: does not have Checkpoint {}.". format(self._data.name, str(cp))) return nv = NewView(viewNo=self._data.view_no, viewChanges=sorted(confirmed_votes, key=itemgetter(0)), checkpoint=cp, batches=batches) logger.info("{} sending {}".format(self, nv)) self._network.send(nv) self._data.new_view_votes.add_new_view(nv, self._data.name) self._finish_view_change() def _finish_view_change_if_needed(self): if self._data.new_view is None: return view_changes = [] for name, vc_digest in self._data.new_view.viewChanges: vc = self.view_change_votes.get_view_change(name, vc_digest) # We don't have needed ViewChange, so we cannot validate NewView if vc is None: self._request_view_change_message((name, vc_digest)) return view_changes.append(vc) cp = self._new_view_builder.calc_checkpoint(view_changes) if cp is None or cp != self._data.new_view.checkpoint: # New primary is malicious logger.info( "{} Received invalid NewView {} for view {}: expected checkpoint {}" .format(self._data.name, self._data.new_view, self._data.view_no, cp)) self._propose_view_change(Suspicions.NEW_VIEW_INVALID_CHECKPOINTS) return batches = self._new_view_builder.calc_batches(cp, view_changes) if batches != self._data.new_view.batches: # New primary is malicious logger.info( "{} Received invalid NewView {} for view {}: expected batches {}" .format(self._data.name, self._data.new_view, self._data.view_no, batches)) self._propose_view_change(Suspicions.NEW_VIEW_INVALID_BATCHES) return self._finish_view_change() def _finish_view_change(self): logger.info( "{} finished view change to view {}. Master Primary: {}".format( self._data.name, self._data.view_no, self._data.primary_name)) # Update shared data self._data.waiting_for_new_view = False self._data.prev_view_prepare_cert = self._data.new_view.batches[-1].pp_seq_no \ if self._data.new_view.batches else self._data.new_view.checkpoint.seqNoEnd # Cancel View Change timeout task self._resend_inst_change_timer.stop() # send message to other services self._bus.send( NewViewAccepted(view_no=self._data.new_view.viewNo, view_changes=self._data.new_view.viewChanges, checkpoint=self._data.new_view.checkpoint, batches=self._data.new_view.batches)) self.last_completed_view_no = self._data.view_no def _propose_view_change_not_complete_in_time(self): self._propose_view_change(Suspicions.INSTANCE_CHANGE_TIMEOUT) if self._data.new_view is None: self._request_new_view_message(self._data.view_no) def _propose_view_change(self, suspicion: Suspicion): self._bus.send(VoteForViewChange(suspicion)) def _request_new_view_message(self, view_no): self._bus.send( MissingMessage(msg_type=NEW_VIEW, key=view_no, inst_id=self._data.inst_id, dst=None, stash_data=None)) def _request_view_change_message(self, key): self._bus.send( MissingMessage(msg_type=VIEW_CHANGE, key=key, inst_id=self._data.inst_id, dst=None, stash_data=None))