test: moving over quorum phases rapid fast; increase stability by proper waiting for the DKG messages

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,15 +398,15 @@ 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)
 
     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__':