Merge bitcoin/bitcoin#33121: test: fix p2p_leak_tx.py

14ae71f test: make notfound_on_unannounced more reliable (David Gumberg)
99bc552 test: fix (w)txid confusion in p2p_leak_tx.py (Martin Zumsande)
576dd97 test: increase timeout in p2p_leak_tx.py (Martin Zumsande)

Pull request description:

  This fixes two issues with `p2p_leak_tx.py`:

  1.) #33090: As far as I can see, this is just the randomness of `NextInvToInbounds`/ `rand_exp_duration`, which has a probability of `e^-(60s/5s) = 6.14×10^−6` to result in a period > 60s (our waiting time), so that the test would fail every 160k runs... Doubling the timeout should be sufficient to lower the probability drastically.

  2.) The subtest `test_notfound_on_unannounced_tx` has some (w)txid confusion: we send a `MSG_TX`-type getdata with a `wtxid` in it, which necessarily always results in a NOTFOUND. Fixed this, and change the subtest to be more deterministic based on `mocktime`.

ACKs for top commit:
  stratospher:
    ACK 14ae71f. nice restructuring using mocktime!
  davidgumberg:
    reACK bitcoin/bitcoin@14ae71f
  vasild:
    ACK 14ae71f

Tree-SHA512: be5a4ca7bf56f82b6fa04d90ef9312dc2e6f8ff7ddf70b39d979dc42fbdd823157109b8b5dc46eb7f81ac1e816f40e6966b3c8a7d384aadee01e2189c20d3e3a

Author: fanquake

test/functional/p2p_leak_tx.py

@@ -15,7 +15,7 @@
 import time
 
 class P2PNode(P2PDataStore):
-    def on_inv(self, msg):
+    def on_inv(self, message):
         pass
 
 
@@ -26,27 +26,28 @@ def set_test_params(self):
     def run_test(self):
         self.gen_node = self.nodes[0]  # The block and tx generating node
         self.miniwallet = MiniWallet(self.gen_node)
+        self.mocktime = int(time.time())
 
         self.test_tx_in_block()
         self.test_notfound_on_replaced_tx()
         self.test_notfound_on_unannounced_tx()
 
     def test_tx_in_block(self):
         self.log.info("Check that a transaction in the last block is uploaded (beneficial for compact block relay)")
+        self.gen_node.setmocktime(self.mocktime)
         inbound_peer = self.gen_node.add_p2p_connection(P2PNode())
 
         self.log.debug("Generate transaction and block")
         inbound_peer.last_message.pop("inv", None)
 
-        self.gen_node.setmocktime(int(time.time())) # pause time based activities
         wtxid = self.miniwallet.send_self_transfer(from_node=self.gen_node)["wtxid"]
         rawmp = self.gen_node.getrawmempool(False, True)
         pi = self.gen_node.getpeerinfo()[0]
         assert_equal(rawmp["mempool_sequence"], 2) # our tx cause mempool activity
         assert_equal(pi["last_inv_sequence"], 1) # that is after the last inv
         assert_equal(pi["inv_to_send"], 1) # and our tx has been queued
-        self.gen_node.setmocktime(0)
-
+        self.mocktime += 120
+        self.gen_node.setmocktime(self.mocktime)
         inbound_peer.wait_until(lambda: "inv" in inbound_peer.last_message and inbound_peer.last_message.get("inv").inv[0].hash == int(wtxid, 16))
 
         rawmp = self.gen_node.getrawmempool(False, True)
@@ -65,15 +66,20 @@ def test_tx_in_block(self):
 
     def test_notfound_on_replaced_tx(self):
         self.gen_node.disconnect_p2ps()
+        self.gen_node.setmocktime(self.mocktime)
         inbound_peer = self.gen_node.add_p2p_connection(P2PTxInvStore())
 
         self.log.info("Transaction tx_a is broadcast")
         tx_a = self.miniwallet.send_self_transfer(from_node=self.gen_node)
+        self.mocktime += 120
+        self.gen_node.setmocktime(self.mocktime)
         inbound_peer.wait_for_broadcast(txns=[tx_a["wtxid"]])
 
         tx_b = tx_a["tx"]
         tx_b.vout[0].nValue -= 9000
         self.gen_node.sendrawtransaction(tx_b.serialize().hex())
+        self.mocktime += 120
+        self.gen_node.setmocktime(self.mocktime)
         inbound_peer.wait_until(lambda: "tx" in inbound_peer.last_message and inbound_peer.last_message.get("tx").tx.wtxid_hex == tx_b.wtxid_hex)
 
         self.log.info("Re-request of tx_a after replacement is answered with notfound")
@@ -96,28 +102,31 @@ def test_notfound_on_unannounced_tx(self):
         self.gen_node.disconnect_p2ps()
         inbound_peer = self.gen_node.add_p2p_connection(P2PNode())  # An "attacking" inbound peer
 
-        MAX_REPEATS = 100
-        self.log.info("Running test up to {} times.".format(MAX_REPEATS))
-        for i in range(MAX_REPEATS):
-            self.log.info('Run repeat {}'.format(i + 1))
-            txid = self.miniwallet.send_self_transfer(from_node=self.gen_node)["wtxid"]
-
-            want_tx = msg_getdata()
-            want_tx.inv.append(CInv(t=MSG_TX, h=int(txid, 16)))
-            with p2p_lock:
-                inbound_peer.last_message.pop('notfound', None)
-            inbound_peer.send_and_ping(want_tx)
-
-            if inbound_peer.last_message.get('notfound'):
-                self.log.debug('tx {} was not yet announced to us.'.format(txid))
-                self.log.debug("node has responded with a notfound message. End test.")
-                assert_equal(inbound_peer.last_message['notfound'].vec[0].hash, int(txid, 16))
-                with p2p_lock:
-                    inbound_peer.last_message.pop('notfound')
-                break
-            else:
-                self.log.debug('tx {} was already announced to us. Try test again.'.format(txid))
-                assert int(txid, 16) in [inv.hash for inv in inbound_peer.last_message['inv'].inv]
+        # Set a mock time so that time does not pass, and gen_node never announces the transaction
+        self.gen_node.setmocktime(self.mocktime)
+        wtxid = int(self.miniwallet.send_self_transfer(from_node=self.gen_node)["wtxid"], 16)
+
+        want_tx = msg_getdata()
+        want_tx.inv.append(CInv(t=MSG_WTX, h=wtxid))
+        with p2p_lock:
+            inbound_peer.last_message.pop('notfound', None)
+        inbound_peer.send_and_ping(want_tx)
+        inbound_peer.wait_until(lambda: "notfound" in inbound_peer.last_message)
+        with p2p_lock:
+            assert_equal(inbound_peer.last_message.get("notfound").vec[0].hash, wtxid)
+            inbound_peer.last_message.pop('notfound')
+
+        # Move mocktime forward and wait for the announcement.
+        inbound_peer.last_message.pop('inv', None)
+        self.mocktime += 120
+        self.gen_node.setmocktime(self.mocktime)
+        inbound_peer.wait_for_inv([CInv(t=MSG_WTX, h=wtxid)], timeout=120)
+
+        # Send the getdata again, this time the node should send us a TX message.
+        inbound_peer.last_message.pop('tx', None)
+        inbound_peer.send_and_ping(want_tx)
+        self.wait_until(lambda: "tx" in inbound_peer.last_message)
+        assert_equal(wtxid, int(inbound_peer.last_message["tx"].tx.wtxid_hex, 16))
 
 
 if __name__ == '__main__':