Merge #12264: Fix versionbits warning test

1e2e09e Fix intermittent failure in p2p-versionbits-warning.py (John Newbery)
3bbd843 Improve comments/logging in p2p-versionbits-warning.py (John Newbery)
ef2beb2 Fix flake8 warnings in p2p-versionbits-warning.py (John Newbery)

Pull request description:

  fixes #12259 (and tidies up the test)

  The problem was that the node was still in IBD at the point the last block was generated. UpdateTip() will not generate a warning if the node is still in IBD:

  https://github.com/bitcoin/bitcoin/blob/cc5870a4057f0322509dde5877fb08258bf4ec50/src/validation.cpp#L2151

  The 'proper' fix would be to remove the overenthusiastic latching in DoWarning:

  https://github.com/bitcoin/bitcoin/blob/cc5870a4057f0322509dde5877fb08258bf4ec50/src/validation.cpp#L2135

  so that more than one warning message can be output to `alertnotify`. Really we should suppress multiple messages of the same type, but allow messages to be output if they're for different warnings. That would mean the test wouldn't need to stop-start the node.

Tree-SHA512: 5c9aa5af7eba3c1350ea28482d57d3d79e3166c6224ceddb5d5a631090081d890d7403015e41f413c22990959a488cf1231f88bb825c54a609b24f89c450a1f6

Author: MarcoFalke

test/functional/feature_versionbits_warning.py

@@ -7,25 +7,24 @@
 Generate chains with block versions that appear to be signalling unknown
 soft-forks, and test that warning alerts are generated.
 """
-
-from test_framework.mininode import *
-from test_framework.test_framework import BitcoinTestFramework
-from test_framework.util import *
+import os
 import re
+
 from test_framework.blocktools import create_block, create_coinbase
+from test_framework.messages import msg_block
+from test_framework.mininode import P2PInterface, network_thread_start, mininode_lock
+from test_framework.test_framework import BitcoinTestFramework
+from test_framework.util import wait_until
 
-VB_PERIOD = 144 # versionbits period length for regtest
-VB_THRESHOLD = 108 # versionbits activation threshold for regtest
+VB_PERIOD = 144           # versionbits period length for regtest
+VB_THRESHOLD = 108        # versionbits activation threshold for regtest
 VB_TOP_BITS = 0x20000000
-VB_UNKNOWN_BIT = 27 # Choose a bit unassigned to any deployment
+VB_UNKNOWN_BIT = 27       # Choose a bit unassigned to any deployment
+VB_UNKNOWN_VERSION = VB_TOP_BITS | (1 << VB_UNKNOWN_BIT)
 
 WARN_UNKNOWN_RULES_MINED = "Unknown block versions being mined! It's possible unknown rules are in effect"
 WARN_UNKNOWN_RULES_ACTIVE = "unknown new rules activated (versionbit {})".format(VB_UNKNOWN_BIT)
-VB_PATTERN = re.compile("^Warning.*versionbit")
-
-class TestNode(P2PInterface):
-    def on_inv(self, message):
-        pass
+VB_PATTERN = re.compile("Warning: unknown new rules activated.*versionbit")
 
 class VersionBitsWarningTest(BitcoinTestFramework):
     def set_test_params(self):
@@ -35,87 +34,79 @@ def set_test_params(self):
     def setup_network(self):
         self.alert_filename = os.path.join(self.options.tmpdir, "alert.txt")
         # Open and close to create zero-length file
-        with open(self.alert_filename, 'w', encoding='utf8') as _:
+        with open(self.alert_filename, 'w', encoding='utf8'):
             pass
         self.extra_args = [["-alertnotify=echo %s >> \"" + self.alert_filename + "\""]]
         self.setup_nodes()
 
-    # Send numblocks blocks via peer with nVersionToUse set.
-    def send_blocks_with_version(self, peer, numblocks, nVersionToUse):
+    def send_blocks_with_version(self, peer, numblocks, version):
+        """Send numblocks blocks to peer with version set"""
         tip = self.nodes[0].getbestblockhash()
         height = self.nodes[0].getblockcount()
-        block_time = self.nodes[0].getblockheader(tip)["time"]+1
+        block_time = self.nodes[0].getblockheader(tip)["time"] + 1
         tip = int(tip, 16)
 
         for _ in range(numblocks):
-            block = create_block(tip, create_coinbase(height+1), block_time)
-            block.nVersion = nVersionToUse
+            block = create_block(tip, create_coinbase(height + 1), block_time)
+            block.nVersion = version
             block.solve()
             peer.send_message(msg_block(block))
             block_time += 1
             height += 1
             tip = block.sha256
         peer.sync_with_ping()
 
-    def test_versionbits_in_alert_file(self):
-        with open(self.alert_filename, 'r', encoding='utf8') as f:
-            alert_text = f.read()
-        assert(VB_PATTERN.match(alert_text))
+    def versionbits_in_alert_file(self):
+        """Test that the versionbits warning has been written to the alert file."""
+        alert_text = open(self.alert_filename, 'r', encoding='utf8').read()
+        return VB_PATTERN.search(alert_text) is not None
 
     def run_test(self):
-        # Setup the p2p connection and start up the network thread.
-        self.nodes[0].add_p2p_connection(TestNode())
-
+        # Handy alias
+        node = self.nodes[0]
+        node.add_p2p_connection(P2PInterface())
         network_thread_start()
+        node.p2p.wait_for_verack()
 
-        # Test logic begins here
-        self.nodes[0].p2p.wait_for_verack()
-
-        # 1. Have the node mine one period worth of blocks
-        self.nodes[0].generate(VB_PERIOD)
-
-        # 2. Now build one period of blocks on the tip, with < VB_THRESHOLD
-        # blocks signaling some unknown bit.
-        nVersion = VB_TOP_BITS | (1<<VB_UNKNOWN_BIT)
-        self.send_blocks_with_version(self.nodes[0].p2p, VB_THRESHOLD-1, nVersion)
-
-        # Fill rest of period with regular version blocks
-        self.nodes[0].generate(VB_PERIOD - VB_THRESHOLD + 1)
-        # Check that we're not getting any versionbit-related errors in
-        # get*info()
-        assert(not VB_PATTERN.match(self.nodes[0].getmininginfo()["warnings"]))
-        assert(not VB_PATTERN.match(self.nodes[0].getnetworkinfo()["warnings"]))
-
-        # 3. Now build one period of blocks with >= VB_THRESHOLD blocks signaling
-        # some unknown bit
-        self.send_blocks_with_version(self.nodes[0].p2p, VB_THRESHOLD, nVersion)
-        self.nodes[0].generate(VB_PERIOD - VB_THRESHOLD)
-        # Might not get a versionbits-related alert yet, as we should
-        # have gotten a different alert due to more than 51/100 blocks
-        # being of unexpected version.
-        # Check that get*info() shows some kind of error.
-        assert(WARN_UNKNOWN_RULES_MINED in self.nodes[0].getmininginfo()["warnings"])
-        assert(WARN_UNKNOWN_RULES_MINED in self.nodes[0].getnetworkinfo()["warnings"])
+        # Mine one period worth of blocks
+        node.generate(VB_PERIOD)
 
-        # Mine a period worth of expected blocks so the generic block-version warning
-        # is cleared, and restart the node. This should move the versionbit state
-        # to ACTIVE.
-        self.nodes[0].generate(VB_PERIOD)
-        self.stop_nodes()
-        # Empty out the alert file
-        with open(self.alert_filename, 'w', encoding='utf8') as _:
-            pass
-        self.start_nodes()
+        self.log.info("Check that there is no warning if previous VB_BLOCKS have <VB_THRESHOLD blocks with unknown versionbits version.")
+        # Build one period of blocks with < VB_THRESHOLD blocks signaling some unknown bit
+        self.send_blocks_with_version(node.p2p, VB_THRESHOLD - 1, VB_UNKNOWN_VERSION)
+        node.generate(VB_PERIOD - VB_THRESHOLD + 1)
+
+        # Check that we're not getting any versionbit-related errors in get*info()
+        assert(not VB_PATTERN.match(node.getmininginfo()["warnings"]))
+        assert(not VB_PATTERN.match(node.getnetworkinfo()["warnings"]))
 
-        # Connecting one block should be enough to generate an error.
-        self.nodes[0].generate(1)
-        assert(WARN_UNKNOWN_RULES_ACTIVE in self.nodes[0].getmininginfo()["warnings"])
-        assert(WARN_UNKNOWN_RULES_ACTIVE in self.nodes[0].getnetworkinfo()["warnings"])
-        self.stop_nodes()
-        self.test_versionbits_in_alert_file()
+        self.log.info("Check that there is a warning if >50 blocks in the last 100 were an unknown version")
+        # Build one period of blocks with VB_THRESHOLD blocks signaling some unknown bit
+        self.send_blocks_with_version(node.p2p, VB_THRESHOLD, VB_UNKNOWN_VERSION)
+        node.generate(VB_PERIOD - VB_THRESHOLD)
 
-        # Test framework expects the node to still be running...
-        self.start_nodes()
+        # Check that get*info() shows the 51/100 unknown block version error.
+        assert(WARN_UNKNOWN_RULES_MINED in node.getmininginfo()["warnings"])
+        assert(WARN_UNKNOWN_RULES_MINED in node.getnetworkinfo()["warnings"])
+
+        self.log.info("Check that there is a warning if previous VB_BLOCKS have >=VB_THRESHOLD blocks with unknown versionbits version.")
+        # Mine a period worth of expected blocks so the generic block-version warning
+        # is cleared. This will move the versionbit state to ACTIVE.
+        node.generate(VB_PERIOD)
+
+        # Stop-start the node. This is required because bitcoind will only warn once about unknown versions or unknown rules activating.
+        self.restart_node(0)
+
+        # Generating one block guarantees that we'll get out of IBD
+        node.generate(1)
+        wait_until(lambda: not node.getblockchaininfo()['initialblockdownload'], timeout=10, lock=mininode_lock)
+        # Generating one more block will be enough to generate an error.
+        node.generate(1)
+        # Check that get*info() shows the versionbits unknown rules warning
+        assert(WARN_UNKNOWN_RULES_ACTIVE in node.getmininginfo()["warnings"])
+        assert(WARN_UNKNOWN_RULES_ACTIVE in node.getnetworkinfo()["warnings"])
+        # Check that the alert file shows the versionbits unknown rules warning
+        wait_until(lambda: self.versionbits_in_alert_file(), timeout=60)
 
 if __name__ == '__main__':
     VersionBitsWarningTest().main()