diff --git a/test/functional/feature_llmq_simplepose.py b/test/functional/feature_llmq_simplepose.py index 4ad57c34c7e3..6fa9e8f3f1cb 100755 --- a/test/functional/feature_llmq_simplepose.py +++ b/test/functional/feature_llmq_simplepose.py @@ -10,8 +10,6 @@ ''' -import time - from test_framework.masternodes import check_banned, check_punished from test_framework.messages import NODE_COMPACT_FILTERS from test_framework.p2p import P2P_SERVICES, P2PInterface @@ -157,9 +155,9 @@ def test_no_service(self, relay, services, reason, banned): assert not check_punished(self.nodes[0], mn) def mine_quorum_no_service(self, mn, others, relay, services, expected_complaints): - # Like mine_quorum, except that mn goes offline once every member holds its contribution and a peer stands - # in for it on each other member with a masternode connection that lacks the service, so that the complain - # phase judges mn by that connection alone. + # Like mine_quorum, except that mn goes offline once every member of every type holds its contribution and + # a peer stands in for it on each other member with a masternode connection that lacks the service, so that + # the complain phase judges mn by that connection alone. self.log.info(f"Mining quorum with a stand-in for {mn.proTxHash}: expected_complaints={expected_complaints}") nodes = [self.nodes[0]] + [m.get_node(self) for m in others] spork23_active = self.nodes[0].spork('show')['SPORK_23_QUORUM_POSE'] <= 1 @@ -172,15 +170,15 @@ def mine_quorum_no_service(self, mn, others, relay, services, expected_complaint q = self.nodes[0].getbestblockhash() self.log.info("Expected quorum_hash:"+str(q)) self.log.info("Waiting for phase 1 (init)") - self.wait_for_quorum_phase(q, 1, len(others), None, 0, others) - self.wait_for_quorum_connections(q, self.llmq_size - 1, others, wait_proc=lambda: self.bump_mocktime(1)) + self.wait_for_quorum_phase(q, 1, len(self.mninfo), None, 0, self.mninfo, all_types=True) + self.wait_for_quorum_connections(q, self.llmq_size - 1, self.mninfo, wait_proc=lambda: self.bump_mocktime(1), all_types=True) if spork23_active: self.wait_for_masternode_probes(q, others, wait_proc=lambda: self.bump_mocktime(1)) self.move_blocks(self.nodes, 2) self.log.info("Waiting for phase 2 (contribute)") - self.wait_for_quorum_phase(q, 2, len(others), "receivedContributions", self.llmq_size, others) + self.wait_for_quorum_phase(q, 2, len(self.mninfo), "receivedContributions", self.llmq_size, self.mninfo, all_types=True) self.log.info("Replacing the connections to the masternode with stand-ins") mn.get_node(self).setnetworkactive(False) @@ -241,9 +239,10 @@ def test_no_banning(self, invalidate_proc, expected_connections=None): self.log.info(f"Testing no PoSe banning in normal conditions {i + 1}/{iters}") self.mine_quorum(expected_connections=expected_connections) - def mine_quorum_less_checks(self, expected_good_nodes, mninfos_online): - # Unlike in mine_quorum we skip most of the checks and only care about - # nodes moving forward from phase to phase correctly and the fact that the quorum is actually mined. + def mine_quorum_less_checks(self, expected_members, mninfos_online): + # Unlike in mine_quorum we don't know how many complaints and justifications to expect: + # the deaf masternode is a regular DKG participant until enough probes to it have failed, + # so each phase waits for exactly the messages the members report having sent instead. self.log.info("Mining a quorum with less checks") nodes = [self.nodes[0]] + [mn.get_node(self) for mn in mninfos_online] @@ -256,31 +255,37 @@ def mine_quorum_less_checks(self, expected_good_nodes, mninfos_online): q = self.nodes[0].getbestblockhash() self.log.info("Expected quorum_hash: "+str(q)) self.log.info("Waiting for phase 1 (init)") - self.wait_for_quorum_phase(q, 1, expected_good_nodes, None, 0, mninfos_online) + self.wait_for_quorum_phase(q, 1, expected_members, None, 0, mninfos_online, all_types=True) + self.wait_for_quorum_connections(q, expected_members - 1, mninfos_online, wait_proc=lambda: self.bump_mocktime(1), all_types=True) + self.log.info("Waiting for this round's probes of the deaf masternodes to be attempted") + self.wait_for_deaf_masternode_probes(mninfos_online) self.move_blocks(nodes, 2) self.log.info("Waiting for phase 2 (contribute)") - self.wait_for_quorum_phase(q, 2, expected_good_nodes, "receivedContributions", expected_good_nodes, mninfos_online) + self.wait_for_quorum_phase(q, 2, expected_members, "receivedContributions", expected_members, mninfos_online, all_types=True) self.move_blocks(nodes, 2) self.log.info("Waiting for phase 3 (complain)") - self.wait_for_quorum_phase(q, 3, expected_good_nodes, None, 0, mninfos_online) + self.wait_for_quorum_phase(q, 3, expected_members, "receivedComplaints", None, mninfos_online, all_types=True) self.move_blocks(nodes, 2) self.log.info("Waiting for phase 4 (justify)") - self.wait_for_quorum_phase(q, 4, expected_good_nodes, None, 0, mninfos_online) + self.wait_for_quorum_phase(q, 4, expected_members, "receivedJustifications", None, mninfos_online, all_types=True) self.move_blocks(nodes, 2) self.log.info("Waiting for phase 5 (commit)") - self.wait_for_quorum_phase(q, 5, expected_good_nodes, "receivedPrematureCommitments", expected_good_nodes, mninfos_online) + self.wait_for_quorum_phase(q, 5, expected_members, "receivedPrematureCommitments", expected_members, mninfos_online, all_types=True) self.move_blocks(nodes, 2) self.log.info("Waiting for phase 6 (mining)") - self.wait_for_quorum_phase(q, 6, expected_good_nodes, None, 0, mninfos_online) + self.wait_for_quorum_phase(q, 6, expected_members, None, 0, mninfos_online, all_types=True) self.log.info("Waiting final commitment") self.wait_for_quorum_commitment(q, mninfos_online) + self.log.info("Waiting final commitments on mining node") + self.wait_for_quorum_commitments_on_miner(q, mninfos_online) + self.log.info("Mining final commitment") self.bump_mocktime(1, nodes=nodes) self.nodes[0].getblocktemplate() # this calls CreateNewBlock @@ -300,6 +305,25 @@ def mine_quorum_less_checks(self, expected_good_nodes, mninfos_online): return new_quorum + def wait_for_deaf_masternode_probes(self, mninfos_online): + # A member marks a deaf masternode bad only once enough probes of it have failed, and a + # probe attempt is counted when the connection is opened, not when the DKG round starts. + # reset_probe_timeouts() moved mocktime 10 minutes ahead of any previous attempt, so a + # younger attempt is this round's one. Already banned deaf masternodes are no members + # and are not probed anymore. + probed_mns = [mn for mn in self.deaf_mns if not check_banned(self.nodes[0], mn)] + + def probes_attempted(): + for mn in mninfos_online: + if mn in self.deaf_mns: + continue + for probed_mn in probed_mns: + if mn.get_node(self).protx('info', probed_mn.proTxHash)['metaInfo']['lastOutboundAttemptElapsed'] > 10 * 60: + return False + return True + + self.wait_until(probes_attempted) + def test_banning(self, invalidate_proc, expected_connections=None): mninfos_online = self.mninfo.copy() mninfos_valid = self.mninfo.copy() @@ -331,13 +355,14 @@ def test_banning(self, invalidate_proc, expected_connections=None): self.reset_probe_timeouts() self.mine_quorum(expected_connections=expected_connections, expected_members=expected_contributors, expected_contributions=expected_contributors, expected_complaints=expected_complaints, expected_commitments=expected_contributors, mninfos_online=mninfos_online, mninfos_valid=mninfos_valid) else: - # It's ok to miss probes/quorum connections up to 5 times. - # 6th time is when it should be banned for sure. + # A member is marked bad once more than MASTERNODE_MAX_FAILED_OUTBOUND_ATTEMPTS (5) + # probes of it failed, i.e. from the 6th DKG round on with one probe per round, and + # each exclusion costs 66% of the ban threshold, so the 7th round bans it for sure. assert expected_connections is None - for j in range(6): - self.log.info(f"Accumulating PoSe penalty {j + 1}/6") + for j in range(7): + self.log.info(f"Accumulating PoSe penalty {j + 1}/7") self.reset_probe_timeouts() - self.mine_quorum_less_checks(expected_contributors - 1, mninfos_online) + self.mine_quorum_less_checks(expected_contributors, mninfos_online) if check_banned(self.nodes[0], mn): break @@ -373,6 +398,8 @@ def repair_masternodes(self, restart): assert not check_banned(self.nodes[0], mn) mn.get_node(self).setnetworkactive(False) self.wait_until(lambda: mn.get_node(self).getconnectioncount() == 0) + # node0 has to notice the drop as well, or it rejects the fresh MNAUTH as a duplicate of the stale peer + self.wait_until(lambda: all(p.get("verified_proregtx_hash") != mn.proTxHash for p in self.nodes[0].getpeerinfo())) mn.get_node(self).setnetworkactive(True) force_finish_mnsync(mn.get_node(self)) self.connect_nodes(mn.nodeIdx, 0) @@ -380,8 +407,6 @@ def repair_masternodes(self, restart): def reset_probe_timeouts(self): # Make sure all masternodes will reconnect/re-probe self.bump_mocktime(10 * 60 + 1) - # Sleep a couple of seconds to let mn sync tick to happen - time.sleep(2) if __name__ == '__main__': diff --git a/test/functional/test_framework/test_framework.py b/test/functional/test_framework/test_framework.py index 202f3c42857b..75125f6a9954 100755 --- a/test/functional/test_framework/test_framework.py +++ b/test/functional/test_framework/test_framework.py @@ -1492,6 +1492,19 @@ def update_service(self, node: TestNode, submit: bool, addrs_core_p2p: Union[str return ret +def throttled(proc, interval=1): + # proc has side effects like bumping mocktime, so run it at most once per interval of real time + # no matter how fast the caller polls + last = 0 + + def run(): + nonlocal last + if time.time() - last >= interval: + proc() + last = time.time() + return run + + class DashTestFramework(BitcoinTestFramework): def set_test_params(self): """Tests must this method to change default values for number of nodes, topology, etc""" @@ -2061,24 +2074,33 @@ def check_sporks_same(): self.bump_mocktime(6, update_schedulers=False) self.wait_until(check_sporks_same, timeout=timeout) - def wait_for_quorum_connections(self, quorum_hash, expected_connections, mninfos, llmq_type_name="llmq_test", timeout = 60, wait_proc=None): + def wait_for_quorum_connections(self, quorum_hash, expected_connections, mninfos, llmq_type_name="llmq_test", timeout = 60, wait_proc=None, all_types=False): + if wait_proc is not None: + # wait_proc bumps mocktime by a second, keep it from outrunning the wall clock + wait_proc = throttled(wait_proc) + def check_quorum_connections(): def ret(): if wait_proc is not None: wait_proc() return False + # With all_types every type running its DKG at this base block has to have its connections + # up as well, or its contributions are lost and wait_for_quorum_phase never sees them; + # expected_connections only applies to the requested type + found = False + online = {mn.proTxHash for mn in mninfos} for mn in mninfos: s = mn.get_node(self).quorum("dkgstatus") for qs in s["session"]: - if qs["llmqType"] != llmq_type_name: + if not all_types and qs["llmqType"] != llmq_type_name: continue if qs["status"]["quorumHash"] != quorum_hash: continue for qc in s["quorumConnections"]: if "quorumConnections" not in qc: continue - if qc["llmqType"] != llmq_type_name: + if qc["llmqType"] != qs["llmqType"]: continue if qc["quorumHash"] != quorum_hash: continue @@ -2088,19 +2110,32 @@ def ret(): for c in qc["quorumConnections"]: if c["connected"]: cnt += 1 - if cnt < expected_connections: - return ret() - return True - # a session with no matching connections - not ok - return ret() + elif c["outbound"] and c["proTxHash"] in online: + # DKG messages are only relayed over the outbound connections, and only to the + # peers connected at the time, so a member must have all of them before it + # sends anything + return ret() + if qs["llmqType"] == llmq_type_name: + if cnt < expected_connections: + return ret() + found = True + break + else: + # a session with no matching connections - not ok + return ret() # a node with no sessions - ok - pass - # no sessions at all - not ok - return ret() + if not found: + # no sessions at all - not ok + return ret() + return True - self.wait_until(check_quorum_connections, timeout=timeout, sleep=1) + self.wait_until(check_quorum_connections, timeout=timeout) def wait_for_masternode_probes(self, quorum_hash, mninfos, timeout = 30, wait_proc=None, llmq_type_name="llmq_test"): + if wait_proc is not None: + # wait_proc bumps mocktime by a second, keep it from outrunning the wall clock + wait_proc = throttled(wait_proc) + def check_probes(): def ret(): if wait_proc is not None: @@ -2136,29 +2171,77 @@ def ret(): return ret() return True - self.wait_until(check_probes, timeout=timeout, sleep=1) + self.wait_until(check_probes, timeout=timeout) + + def wait_for_quorum_phase(self, quorum_hash, phase, expected_member_count, check_received_messages, check_received_messages_count, mninfos, llmq_type_name="llmq_test", timeout=30, all_types=False): + # A member reports a phase only once its own messages of that phase are sent, so with + # check_received_messages_count=None the members' sent* flags give the exact number of + # messages every member has to receive before the DKG may move on + sent_flags = { + "receivedContributions": "sentContributions", + "receivedComplaints": "sentComplaint", + "receivedJustifications": "sentJustification", + "receivedPrematureCommitments": "sentPrematureCommitment", + } + + # A masternode PoSe-banned after its selection into a quarter of a rotating quorum stays in + # that quorum's composition while the quarter is reused, but a banned masternode joins no DKG + online = {mn.proTxHash for mn in mninfos if not check_banned(self.nodes[0], mn)} + + def dkg_members(dkgstatus): + # The quorum connections of every type whose DKG runs at this base block come from the + # member selection itself, so unlike a session they are listed before a member's handler + # thread has noticed the block. Each masternode lists the members it has to be connected + # to, which together name every member of the type. + members = {} + for qc in dkgstatus["quorumConnections"]: + if qc.get("quorumHash") != quorum_hash: + continue + members.setdefault(qc["llmqType"], set()).update(c["proTxHash"] for c in qc["quorumConnections"]) + return members - def wait_for_quorum_phase(self, quorum_hash, phase, expected_member_count, check_received_messages, check_received_messages_count, mninfos, llmq_type_name="llmq_test", timeout=30, sleep=0.5): def check_dkg_session(): - member_count = 0 + # Every llmq type runs its DKG at this base block at once, and the commitments of the + # others apply PoSe penalties just the same, so with all_types all of them have to get + # their messages through before the next phase is mined; only the requested type has + # known counts. Offline members break the relay graph of the other types, so their + # messages can't be expected to arrive then. + statuses = {} + members = {} for mn in mninfos: - s = mn.get_node(self).quorum("dkgstatus")["session"] - for qs in s: - if qs["llmqType"] != llmq_type_name: + dkgstatus = mn.get_node(self).quorum("dkgstatus") + if all_types: + for llmq_type, type_members in dkg_members(dkgstatus).items(): + members.setdefault(llmq_type, set()).update(type_members) + for qs in dkgstatus["session"]: + if not all_types and qs["llmqType"] != llmq_type_name: continue qstatus = qs["status"] if qstatus["quorumHash"] != quorum_hash: continue if qstatus["phase"] != phase: return False - if check_received_messages is not None: - if qstatus[check_received_messages] < check_received_messages_count: - return False - member_count += 1 - break - return member_count >= expected_member_count + statuses.setdefault(qs["llmqType"], []).append(qstatus) + if len(statuses.get(llmq_type_name, [])) < expected_member_count: + return False + for llmq_type, type_members in members.items(): + # A member reports the phase only once its handler thread has entered the round, and + # one that enters late has missed the messages sent so far, so every member has to be + # in before the DKG moves on. A DKG with fewer members than the type's minimum size + # never starts. + min_size = {"llmq_test_dip0024": self.llmq_size_dip0024, "llmq_test_v17": 2}.get(llmq_type, self.llmq_threshold) + if len(type_members) >= min_size and len(statuses.get(llmq_type, [])) < len(type_members & online): + return False + if check_received_messages is not None: + for llmq_type, type_statuses in statuses.items(): + expected = check_received_messages_count if llmq_type == llmq_type_name else None + if expected is None: + expected = sum(qstatus[sent_flags[check_received_messages]] for qstatus in type_statuses) + if any(qstatus[check_received_messages] < expected for qstatus in type_statuses): + return False + return True - self.wait_until(check_dkg_session, timeout=timeout, sleep=sleep) + self.wait_until(check_dkg_session, timeout=timeout) def node_quorum_commitment_types(self, node, quorum_hash): s = node.quorum("dkgstatus") @@ -2250,6 +2333,7 @@ def mine_quorum(self, llmq_type_name="llmq_test", llmq_type=100, expected_connec expected_justifications, expected_commitments)) nodes = [self.nodes[0]] + [mn.get_node(self) for mn in mninfos_online] + all_types = len(mninfos_online) == len(self.mninfo) # move forward to next DKG llmq_cycle_len = 24 @@ -2268,35 +2352,35 @@ def mine_quorum(self, llmq_type_name="llmq_test", llmq_type=100, expected_connec q = self.nodes[0].getbestblockhash() self.log.info("Expected quorum_hash:"+str(q)) self.log.info("Waiting for phase 1 (init)") - self.wait_for_quorum_phase(q, 1, expected_members, None, 0, mninfos_online, llmq_type_name=llmq_type_name) - self.wait_for_quorum_connections(q, expected_connections, mninfos_online, wait_proc=lambda: self.bump_mocktime(1), llmq_type_name=llmq_type_name) + self.wait_for_quorum_phase(q, 1, expected_members, None, 0, mninfos_online, llmq_type_name=llmq_type_name, all_types=all_types) + self.wait_for_quorum_connections(q, expected_connections, mninfos_online, wait_proc=lambda: self.bump_mocktime(1), llmq_type_name=llmq_type_name, all_types=all_types) if spork23_active: self.wait_for_masternode_probes(q, mninfos_online, wait_proc=lambda: self.bump_mocktime(1)) self.move_blocks(nodes, 2) self.log.info("Waiting for phase 2 (contribute)") - self.wait_for_quorum_phase(q, 2, expected_members, "receivedContributions", expected_contributions, mninfos_online, llmq_type_name=llmq_type_name) + self.wait_for_quorum_phase(q, 2, expected_members, "receivedContributions", expected_contributions, mninfos_online, llmq_type_name=llmq_type_name, all_types=all_types) self.move_blocks(nodes, 2) self.log.info("Waiting for phase 3 (complain)") - self.wait_for_quorum_phase(q, 3, expected_members, "receivedComplaints", expected_complaints, mninfos_online, llmq_type_name=llmq_type_name) + self.wait_for_quorum_phase(q, 3, expected_members, "receivedComplaints", expected_complaints, mninfos_online, llmq_type_name=llmq_type_name, all_types=all_types) self.move_blocks(nodes, 2) self.log.info("Waiting for phase 4 (justify)") - self.wait_for_quorum_phase(q, 4, expected_members, "receivedJustifications", expected_justifications, mninfos_online, llmq_type_name=llmq_type_name) + self.wait_for_quorum_phase(q, 4, expected_members, "receivedJustifications", expected_justifications, mninfos_online, llmq_type_name=llmq_type_name, all_types=all_types) self.move_blocks(nodes, 2) self.log.info("Waiting for phase 5 (commit)") - self.wait_for_quorum_phase(q, 5, expected_members, "receivedPrematureCommitments", expected_commitments, mninfos_online, llmq_type_name=llmq_type_name) + self.wait_for_quorum_phase(q, 5, expected_members, "receivedPrematureCommitments", expected_commitments, mninfos_online, llmq_type_name=llmq_type_name, all_types=all_types) self.move_blocks(nodes, 2) self.log.info("Waiting for phase 6 (mining)") - self.wait_for_quorum_phase(q, 6, expected_members, None, 0, mninfos_online, llmq_type_name=llmq_type_name) + self.wait_for_quorum_phase(q, 6, expected_members, None, 0, mninfos_online, llmq_type_name=llmq_type_name, all_types=all_types) self.log.info("Waiting final commitment") self.wait_for_quorum_commitment(q, mninfos_online, llmq_type=llmq_type) @@ -2430,9 +2514,9 @@ def mine_cycle_quorum(self): self.log.info("Expected quorum_0 at:" + str(self.nodes[0].getblockcount())) self.log.info("Expected quorum_0 hash:" + str(q_0)) self.log.info("quorumIndex 0: Waiting for phase 1 (init)") - self.wait_for_quorum_phase(q_0, 1, expected_members, None, 0, mninfos_online, llmq_type_name) + self.wait_for_quorum_phase(q_0, 1, expected_members, None, 0, mninfos_online, llmq_type_name, all_types=True) self.log.info("quorumIndex 0: Waiting for quorum connections (init)") - self.wait_for_quorum_connections(q_0, expected_connections, mninfos_online, llmq_type_name, wait_proc=lambda: self.bump_mocktime(1)) + self.wait_for_quorum_connections(q_0, expected_connections, mninfos_online, llmq_type_name, wait_proc=lambda: self.bump_mocktime(1), all_types=True) if spork23_active: self.wait_for_masternode_probes(q_0, mninfos_online, wait_proc=lambda: self.bump_mocktime(1), llmq_type_name=llmq_type_name) @@ -2445,61 +2529,70 @@ def mine_cycle_quorum(self): self.log.info("Expected quorum_1 at:" + str(self.nodes[0].getblockcount())) self.log.info("Expected quorum_1 hash:" + str(q_1)) self.log.info("quorumIndex 1: Waiting for phase 1 (init)") - self.wait_for_quorum_phase(q_1, 1, expected_members, None, 0, mninfos_online, llmq_type_name) + self.wait_for_quorum_phase(q_1, 1, expected_members, None, 0, mninfos_online, llmq_type_name, all_types=True) self.log.info("quorumIndex 1: Waiting for quorum connections (init)") - self.wait_for_quorum_connections(q_1, expected_connections, mninfos_online, llmq_type_name, wait_proc=lambda: self.bump_mocktime(1)) + self.wait_for_quorum_connections(q_1, expected_connections, mninfos_online, llmq_type_name, wait_proc=lambda: self.bump_mocktime(1), all_types=True) if spork23_active: self.wait_for_masternode_probes(q_1, mninfos_online, wait_proc=lambda: self.bump_mocktime(1), llmq_type_name=llmq_type_name) self.move_blocks(nodes, 1) self.log.info("quorumIndex 0: Waiting for phase 2 (contribute)") - self.wait_for_quorum_phase(q_0, 2, expected_members, "receivedContributions", expected_contributions, mninfos_online, llmq_type_name) + self.wait_for_quorum_phase(q_0, 2, expected_members, "receivedContributions", expected_contributions, mninfos_online, llmq_type_name, all_types=True) self.move_blocks(nodes, 1) self.log.info("quorumIndex 1: Waiting for phase 2 (contribute)") - self.wait_for_quorum_phase(q_1, 2, expected_members, "receivedContributions", expected_contributions, mninfos_online, llmq_type_name) + self.wait_for_quorum_phase(q_1, 2, expected_members, "receivedContributions", expected_contributions, mninfos_online, llmq_type_name, all_types=True) self.move_blocks(nodes, 1) self.log.info("quorumIndex 0: Waiting for phase 3 (complain)") - self.wait_for_quorum_phase(q_0, 3, expected_members, "receivedComplaints", expected_complaints, mninfos_online, llmq_type_name) + self.wait_for_quorum_phase(q_0, 3, expected_members, "receivedComplaints", expected_complaints, mninfos_online, llmq_type_name, all_types=True) self.move_blocks(nodes, 1) self.log.info("quorumIndex 1: Waiting for phase 3 (complain)") - self.wait_for_quorum_phase(q_1, 3, expected_members, "receivedComplaints", expected_complaints, mninfos_online, llmq_type_name) + self.wait_for_quorum_phase(q_1, 3, expected_members, "receivedComplaints", expected_complaints, mninfos_online, llmq_type_name, all_types=True) self.move_blocks(nodes, 1) self.log.info("quorumIndex 0: Waiting for phase 4 (justify)") - self.wait_for_quorum_phase(q_0, 4, expected_members, "receivedJustifications", expected_justifications, mninfos_online, llmq_type_name) + self.wait_for_quorum_phase(q_0, 4, expected_members, "receivedJustifications", expected_justifications, mninfos_online, llmq_type_name, all_types=True) self.move_blocks(nodes, 1) self.log.info("quorumIndex 1: Waiting for phase 4 (justify)") - self.wait_for_quorum_phase(q_1, 4, expected_members, "receivedJustifications", expected_justifications, mninfos_online, llmq_type_name) + self.wait_for_quorum_phase(q_1, 4, expected_members, "receivedJustifications", expected_justifications, mninfos_online, llmq_type_name, all_types=True) self.move_blocks(nodes, 1) self.log.info("quorumIndex 0: Waiting for phase 5 (commit)") - self.wait_for_quorum_phase(q_0, 5, expected_members, "receivedPrematureCommitments", expected_commitments, mninfos_online, llmq_type_name) + self.wait_for_quorum_phase(q_0, 5, expected_members, "receivedPrematureCommitments", expected_commitments, mninfos_online, llmq_type_name, all_types=True) self.move_blocks(nodes, 1) self.log.info("quorumIndex 1: Waiting for phase 5 (commit)") - self.wait_for_quorum_phase(q_1, 5, expected_members, "receivedPrematureCommitments", expected_commitments, mninfos_online, llmq_type_name) + self.wait_for_quorum_phase(q_1, 5, expected_members, "receivedPrematureCommitments", expected_commitments, mninfos_online, llmq_type_name, all_types=True) self.move_blocks(nodes, 1) self.log.info("quorumIndex 0: Waiting for phase 6 (finalization)") - self.wait_for_quorum_phase(q_0, 6, expected_members, None, 0, mninfos_online, llmq_type_name) + self.wait_for_quorum_phase(q_0, 6, expected_members, None, 0, mninfos_online, llmq_type_name, all_types=True) self.move_blocks(nodes, 1) self.log.info("quorumIndex 1: Waiting for phase 6 (finalization)") - self.wait_for_quorum_phase(q_1, 6, expected_members, None, 0, mninfos_online, llmq_type_name) + self.wait_for_quorum_phase(q_1, 6, expected_members, None, 0, mninfos_online, llmq_type_name, all_types=True) + + self.log.info("Waiting final commitments") + self.wait_for_quorum_commitment(q_0, mninfos_online, llmq_type=llmq_type) + self.wait_for_quorum_commitment(q_1, mninfos_online, llmq_type=llmq_type) + + self.log.info("Waiting final commitments on mining node") + self.wait_for_quorum_commitments_on_miner(q_0, mninfos_online) + self.wait_for_quorum_commitments_on_miner(q_1, mninfos_online) + self.log.info("Mining final commitments") self.bump_mocktime(1) self.nodes[0].getblocktemplate() # this calls CreateNewBlock @@ -2534,13 +2627,15 @@ def mine_cycle_quorum(self): return (quorum_info_0, quorum_info_1) def wait_for_recovered_sig(self, rec_sig_id, rec_sig_msg_hash, llmq_type=100, timeout=10): + bump_mocktime = throttled(lambda: self.bump_mocktime(1)) + def check_recovered_sig(): - self.bump_mocktime(1) + bump_mocktime() for mn in self.mninfo: # type: MasternodeInfo if not mn.get_node(self).quorum("hasrecsig", llmq_type, rec_sig_id, rec_sig_msg_hash): return False return True - self.wait_until(check_recovered_sig, timeout=timeout, sleep=1) + self.wait_until(check_recovered_sig, timeout=timeout) def get_recovered_sig(self, rec_sig_id, rec_sig_msg_hash, llmq_type=100, use_platformsign=False): # Note: recsigs aren't relayed to regular nodes by default, @@ -2586,14 +2681,20 @@ def test_mn_quorum_data(self, test_mn: MasternodeInfo, quorum_type_in, quorum_ha def wait_for_quorum_data(self, mns, quorum_type_in, quorum_hash_in, test_secret=True, expect_secret=True, recover=False, timeout=60): + def expire_request(): + if self.mocktime % 2: + self.bump_mocktime(self.quorum_data_request_expiration_timeout + 1) + self.generate(self.nodes[0], 1, sync_fun=lambda: self.sync_blocks()) + else: + self.bump_mocktime(self.quorum_data_thread_request_timeout_seconds + 1) + # the recovery thread retries once per real second, so give it the time to answer a request + # before the next one is expired + expire_request = throttled(expire_request, 0.5) + def test_mns(): valid = 0 if recover: - if self.mocktime % 2: - self.bump_mocktime(self.quorum_data_request_expiration_timeout + 1) - self.generate(self.nodes[0], 1, sync_fun=lambda: self.sync_blocks()) - else: - self.bump_mocktime(self.quorum_data_thread_request_timeout_seconds + 1) + expire_request() for test_mn in mns: valid += self.test_mn_quorum_data(test_mn, quorum_type_in, quorum_hash_in, test_secret, expect_secret) @@ -2601,7 +2702,7 @@ def test_mns(): (valid, len(mns), quorum_type_in, quorum_hash_in)) return valid == len(mns) - self.wait_until(test_mns, timeout=timeout, sleep=0.5) + self.wait_until(test_mns, timeout=timeout) def wait_for_mnauth(self, node, count, timeout=10): def test():