From 16c87d91fd4d7709fa9d8824d5b641ef71821931 Mon Sep 17 00:00:00 2001 From: Fabian Jahr Date: Thu, 12 Sep 2024 14:00:08 +0200 Subject: [PATCH 1/3] test: Introduce ensure_for helper --- test/functional/feature_assumeutxo.py | 5 ++--- test/functional/feature_minchainwork.py | 20 +++++++++----------- test/functional/interface_zmq.py | 5 ++--- test/functional/mempool_unbroadcast.py | 11 ++++++----- test/functional/p2p_segwit.py | 7 +++---- test/functional/test_framework/util.py | 21 +++++++++++++++++++++ test/functional/wallet_multiwallet.py | 5 ++--- 7 files changed, 45 insertions(+), 29 deletions(-) diff --git a/test/functional/feature_assumeutxo.py b/test/functional/feature_assumeutxo.py index 57f34264ec..08d47d1e87 100755 --- a/test/functional/feature_assumeutxo.py +++ b/test/functional/feature_assumeutxo.py @@ -9,7 +9,6 @@ to a hash that has been compiled into bitcoind. The assumeutxo value generated and used here is committed to in `CRegTestParams::m_assumeutxo_data` in `src/kernel/chainparams.cpp`. """ -import time from shutil import rmtree from dataclasses import dataclass @@ -31,6 +30,7 @@ from test_framework.util import ( assert_approx, assert_equal, assert_raises_rpc_error, + ensure_for, sha256sum_file, try_rpc, ) @@ -305,8 +305,7 @@ class AssumeutxoTest(BitcoinTestFramework): # If it does request such blocks, the snapshot_node will ignore requests it cannot fulfill, causing the ibd_node # to stall. This stall could last for up to 10 min, ultimately resulting in an abrupt disconnection due to the # ibd_node's perceived unresponsiveness. - time.sleep(3) # Sleep here because we can't detect when a node avoids requesting blocks from other peer. - assert_equal(len(ibd_node.getpeerinfo()[0]['inflight']), 0) + ensure_for(duration=3, f=lambda: len(ibd_node.getpeerinfo()[0]['inflight']) == 0) # Now disconnect nodes and finish background chain sync self.disconnect_nodes(ibd_node.index, snapshot_node.index) diff --git a/test/functional/feature_minchainwork.py b/test/functional/feature_minchainwork.py index 34228f6f38..d6654ef8ed 100755 --- a/test/functional/feature_minchainwork.py +++ b/test/functional/feature_minchainwork.py @@ -19,7 +19,10 @@ import time from test_framework.p2p import P2PInterface, msg_getheaders from test_framework.test_framework import BitcoinTestFramework -from test_framework.util import assert_equal +from test_framework.util import ( + assert_equal, + ensure_for, +) # 2 hashes required per regtest block (with no difficulty adjustment) REGTEST_WORK_PER_BLOCK = 2 @@ -58,18 +61,14 @@ class MinimumChainWorkTest(BitcoinTestFramework): hashes = self.generate(self.nodes[0], num_blocks_to_generate, sync_fun=self.no_op) self.log.info(f"Node0 current chain work: {self.nodes[0].getblockheader(hashes[-1])['chainwork']}") - - # Sleep a few seconds and verify that node2 didn't get any new blocks - # or headers. We sleep, rather than sync_blocks(node0, node1) because - # it's reasonable either way for node1 to get the blocks, or not get - # them (since they're below node1's minchainwork). - time.sleep(3) - self.log.info("Verifying node 2 has no more blocks than before") self.log.info(f"Blockcounts: {[n.getblockcount() for n in self.nodes]}") # Node2 shouldn't have any new headers yet, because node1 should not # have relayed anything. - assert_equal(len(self.nodes[2].getchaintips()), 1) + # We wait 3 seconds, rather than sync_blocks(node0, node1) because + # it's reasonable either way for node1 to get the blocks, or not get + # them (since they're below node1's minchainwork). + ensure_for(duration=3, f=lambda: len(self.nodes[2].getchaintips()) == 1) assert_equal(self.nodes[2].getchaintips()[0]['height'], 0) assert self.nodes[1].getbestblockhash() != self.nodes[0].getbestblockhash() @@ -81,8 +80,7 @@ class MinimumChainWorkTest(BitcoinTestFramework): msg.locator.vHave = [int(self.nodes[2].getbestblockhash(), 16)] msg.hashstop = 0 peer.send_and_ping(msg) - time.sleep(5) - assert "headers" not in peer.last_message or len(peer.last_message["headers"].headers) == 0 + ensure_for(duration=5, f=lambda: "headers" not in peer.last_message or len(peer.last_message["headers"].headers) == 0) self.log.info("Generating one more block") self.generate(self.nodes[0], 1) diff --git a/test/functional/interface_zmq.py b/test/functional/interface_zmq.py index b960f40ccc..74860cd0b8 100755 --- a/test/functional/interface_zmq.py +++ b/test/functional/interface_zmq.py @@ -6,7 +6,6 @@ import os import struct import tempfile -from time import sleep from io import BytesIO from test_framework.address import ( @@ -27,6 +26,7 @@ from test_framework.messages import ( from test_framework.util import ( assert_equal, assert_raises_rpc_error, + ensure_for, p2p_port, ) from test_framework.wallet import ( @@ -394,11 +394,10 @@ class ZMQTest (BitcoinTestFramework): block_count = self.nodes[0].getblockcount() best_hash = self.nodes[0].getbestblockhash() self.nodes[0].invalidateblock(best_hash) - sleep(2) # Bit of room to make sure transaction things happened # Make sure getrawmempool mempool_sequence results aren't "queued" but immediately reflective # of the time they were gathered. - assert self.nodes[0].getrawmempool(mempool_sequence=True)["mempool_sequence"] > seq_num + ensure_for(duration=2, f=lambda: self.nodes[0].getrawmempool(mempool_sequence=True)["mempool_sequence"] > seq_num) assert_equal((best_hash, "D", None), seq.receive_sequence()) assert_equal((rbf_txid, "A", seq_num), seq.receive_sequence()) diff --git a/test/functional/mempool_unbroadcast.py b/test/functional/mempool_unbroadcast.py index 7c96b4b570..b9692d2e21 100755 --- a/test/functional/mempool_unbroadcast.py +++ b/test/functional/mempool_unbroadcast.py @@ -5,11 +5,12 @@ """Test that the mempool ensures transaction delivery by periodically sending to peers until a GETDATA is received.""" -import time - from test_framework.p2p import P2PTxInvStore from test_framework.test_framework import BitcoinTestFramework -from test_framework.util import assert_equal +from test_framework.util import ( + assert_equal, + ensure_for, +) from test_framework.wallet import MiniWallet MAX_INITIAL_BROADCAST_DELAY = 15 * 60 # 15 minutes in seconds @@ -83,8 +84,8 @@ class MempoolUnbroadcastTest(BitcoinTestFramework): conn = node.add_p2p_connection(P2PTxInvStore()) node.mockscheduler(MAX_INITIAL_BROADCAST_DELAY) - time.sleep(2) # allow sufficient time for possibility of broadcast - assert_equal(len(conn.get_invs()), 0) + # allow sufficient time for possibility of broadcast + ensure_for(duration=2, f=lambda: len(conn.get_invs()) == 0) self.disconnect_nodes(0, 1) node.disconnect_p2ps() diff --git a/test/functional/p2p_segwit.py b/test/functional/p2p_segwit.py index 9be53d2ab8..ac35762427 100755 --- a/test/functional/p2p_segwit.py +++ b/test/functional/p2p_segwit.py @@ -5,7 +5,6 @@ """Test segwit transactions and blocks on P2P network.""" from decimal import Decimal import random -import time from test_framework.blocktools import ( WITNESS_COMMITMENT_HEADER, @@ -83,8 +82,9 @@ from test_framework.script_util import ( from test_framework.test_framework import BitcoinTestFramework from test_framework.util import ( assert_equal, - softfork_active, assert_raises_rpc_error, + ensure_for, + softfork_active, ) from test_framework.wallet import MiniWallet from test_framework.wallet_util import generate_keypair @@ -184,8 +184,7 @@ class TestP2PConn(P2PInterface): else: self.wait_for_getdata([tx.sha256]) else: - time.sleep(5) - assert not self.last_message.get("getdata") + ensure_for(duration=5, f=lambda: not self.last_message.get("getdata")) def announce_block_and_wait_for_getdata(self, block, use_header, timeout=60): with p2p_lock: diff --git a/test/functional/test_framework/util.py b/test/functional/test_framework/util.py index ce68de7eaa..c2fc9f2b0a 100644 --- a/test/functional/test_framework/util.py +++ b/test/functional/test_framework/util.py @@ -268,6 +268,27 @@ def satoshi_round(amount: Union[int, float, str], *, rounding: str) -> Decimal: return Decimal(amount).quantize(SATOSHI_PRECISION, rounding=rounding) +def ensure_for(*, duration, f, check_interval=0.2): + """Check if the predicate keeps returning True for duration. + + check_interval can be used to configure the wait time between checks. + Setting check_interval to 0 will allow to have two checks: one in the + beginning and one after duration. + """ + # If check_interval is 0 or negative or larger than duration, we fall back + # to checking once in the beginning and once at the end of duration + if check_interval <= 0 or check_interval > duration: + check_interval = duration + time_end = time.time() + duration + predicate_source = "''''\n" + inspect.getsource(f) + "'''" + while True: + if not f(): + raise AssertionError(f"Predicate {predicate_source} became false within {duration} seconds") + if time.time() > time_end: + return + time.sleep(check_interval) + + def wait_until_helper_internal(predicate, *, attempts=float('inf'), timeout=float('inf'), lock=None, timeout_factor=1.0): """Sleep until the predicate resolves to be True. diff --git a/test/functional/wallet_multiwallet.py b/test/functional/wallet_multiwallet.py index 156f4279b4..a25c96f7a7 100755 --- a/test/functional/wallet_multiwallet.py +++ b/test/functional/wallet_multiwallet.py @@ -12,7 +12,6 @@ import os import platform import shutil import stat -import time from test_framework.authproxy import JSONRPCException from test_framework.blocktools import COINBASE_MATURITY @@ -21,6 +20,7 @@ from test_framework.test_node import ErrorMatch from test_framework.util import ( assert_equal, assert_raises_rpc_error, + ensure_for, get_rpc_proxy, ) @@ -373,8 +373,7 @@ class MultiWalletTest(BitcoinTestFramework): w2.encryptwallet('test') w2.walletpassphrase('test', 1) w2.unloadwallet() - time.sleep(1.1) - assert 'w2' not in self.nodes[0].listwallets() + ensure_for(duration=1.1, f=lambda: 'w2' not in self.nodes[0].listwallets()) # Successfully unload all wallets for wallet_name in self.nodes[0].listwallets(): From 5468a23eb9a3fd2b0c08dbca69fe3df58af42530 Mon Sep 17 00:00:00 2001 From: Fabian Jahr Date: Sat, 21 Sep 2024 21:23:14 +0200 Subject: [PATCH 2/3] test: Add check_interval parameter to wait_until This also replaces two sleep calls in functional tests with wait_until --- test/functional/test_framework/p2p.py | 4 ++-- test/functional/test_framework/test_framework.py | 4 ++-- test/functional/test_framework/test_node.py | 4 ++-- test/functional/test_framework/util.py | 4 ++-- test/functional/wallet_inactive_hdchains.py | 8 ++++---- 5 files changed, 12 insertions(+), 12 deletions(-) diff --git a/test/functional/test_framework/p2p.py b/test/functional/test_framework/p2p.py index 4f1265eb54..8ccd3e44a6 100755 --- a/test/functional/test_framework/p2p.py +++ b/test/functional/test_framework/p2p.py @@ -579,13 +579,13 @@ class P2PInterface(P2PConnection): # Connection helper methods - def wait_until(self, test_function_in, *, timeout=60, check_connected=True): + def wait_until(self, test_function_in, *, timeout=60, check_connected=True, check_interval=0.05): def test_function(): if check_connected: assert self.is_connected return test_function_in() - wait_until_helper_internal(test_function, timeout=timeout, lock=p2p_lock, timeout_factor=self.timeout_factor) + wait_until_helper_internal(test_function, timeout=timeout, lock=p2p_lock, timeout_factor=self.timeout_factor, check_interval=check_interval) def wait_for_connect(self, *, timeout=60): test_function = lambda: self.is_connected diff --git a/test/functional/test_framework/test_framework.py b/test/functional/test_framework/test_framework.py index 49212eb019..19003d44f2 100755 --- a/test/functional/test_framework/test_framework.py +++ b/test/functional/test_framework/test_framework.py @@ -787,8 +787,8 @@ class BitcoinTestFramework(metaclass=BitcoinTestMetaClass): self.sync_blocks(nodes) self.sync_mempools(nodes) - def wait_until(self, test_function, timeout=60): - return wait_until_helper_internal(test_function, timeout=timeout, timeout_factor=self.options.timeout_factor) + def wait_until(self, test_function, timeout=60, check_interval=0.05): + return wait_until_helper_internal(test_function, timeout=timeout, timeout_factor=self.options.timeout_factor, check_interval=check_interval) # Private helper methods. These should not be accessed by the subclass test scripts. diff --git a/test/functional/test_framework/test_node.py b/test/functional/test_framework/test_node.py index 60ca9269a5..bf1f2112b2 100755 --- a/test/functional/test_framework/test_node.py +++ b/test/functional/test_framework/test_node.py @@ -838,8 +838,8 @@ class TestNode(): self.mocktime += seconds self.setmocktime(self.mocktime) - def wait_until(self, test_function, timeout=60): - return wait_until_helper_internal(test_function, timeout=timeout, timeout_factor=self.timeout_factor) + def wait_until(self, test_function, timeout=60, check_interval=0.05): + return wait_until_helper_internal(test_function, timeout=timeout, timeout_factor=self.timeout_factor, check_interval=check_interval) class TestNodeCLIAttr: diff --git a/test/functional/test_framework/util.py b/test/functional/test_framework/util.py index c2fc9f2b0a..6e88a50cd7 100644 --- a/test/functional/test_framework/util.py +++ b/test/functional/test_framework/util.py @@ -289,7 +289,7 @@ def ensure_for(*, duration, f, check_interval=0.2): time.sleep(check_interval) -def wait_until_helper_internal(predicate, *, attempts=float('inf'), timeout=float('inf'), lock=None, timeout_factor=1.0): +def wait_until_helper_internal(predicate, *, attempts=float('inf'), timeout=float('inf'), lock=None, timeout_factor=1.0, check_interval=0.05): """Sleep until the predicate resolves to be True. Warning: Note that this method is not recommended to be used in tests as it is @@ -313,7 +313,7 @@ def wait_until_helper_internal(predicate, *, attempts=float('inf'), timeout=floa if predicate(): return attempt += 1 - time.sleep(0.05) + time.sleep(check_interval) # Print the cause of the timeout predicate_source = "''''\n" + inspect.getsource(predicate) + "'''" diff --git a/test/functional/wallet_inactive_hdchains.py b/test/functional/wallet_inactive_hdchains.py index 3b0c09c02b..1a2ea5b9ff 100755 --- a/test/functional/wallet_inactive_hdchains.py +++ b/test/functional/wallet_inactive_hdchains.py @@ -6,7 +6,6 @@ Test Inactive HD Chains. """ import shutil -import time from test_framework.authproxy import JSONRPCException from test_framework.test_framework import BitcoinTestFramework @@ -75,12 +74,13 @@ class InactiveHDChainsTest(BitcoinTestFramework): self.generate(self.nodes[0], 1) # Wait for the test wallet to see the transaction - while True: + def is_tx_available(txid): try: test_wallet.gettransaction(txid) - break + return True except JSONRPCException: - time.sleep(0.1) + return False + self.nodes[0].wait_until(lambda: is_tx_available(txid), timeout=10, check_interval=0.1) if encrypt: # The test wallet will not be able to generate the topped up keypool From 111465d72dd35e42361fc2a089036f652417ed37 Mon Sep 17 00:00:00 2001 From: Fabian Jahr Date: Sun, 29 Sep 2024 22:24:31 +0200 Subject: [PATCH 3/3] test: Remove unused attempts parameter from wait_until --- test/functional/test_framework/util.py | 14 +++----------- 1 file changed, 3 insertions(+), 11 deletions(-) diff --git a/test/functional/test_framework/util.py b/test/functional/test_framework/util.py index 6e88a50cd7..6947ac5895 100644 --- a/test/functional/test_framework/util.py +++ b/test/functional/test_framework/util.py @@ -289,7 +289,7 @@ def ensure_for(*, duration, f, check_interval=0.2): time.sleep(check_interval) -def wait_until_helper_internal(predicate, *, attempts=float('inf'), timeout=float('inf'), lock=None, timeout_factor=1.0, check_interval=0.05): +def wait_until_helper_internal(predicate, *, timeout=60, lock=None, timeout_factor=1.0, check_interval=0.05): """Sleep until the predicate resolves to be True. Warning: Note that this method is not recommended to be used in tests as it is @@ -298,13 +298,10 @@ def wait_until_helper_internal(predicate, *, attempts=float('inf'), timeout=floa properly scaled. Furthermore, `wait_until()` from `P2PInterface` class in `p2p.py` has a preset lock. """ - if attempts == float('inf') and timeout == float('inf'): - timeout = 60 timeout = timeout * timeout_factor - attempt = 0 time_end = time.time() + timeout - while attempt < attempts and time.time() < time_end: + while time.time() < time_end: if lock: with lock: if predicate(): @@ -312,17 +309,12 @@ def wait_until_helper_internal(predicate, *, attempts=float('inf'), timeout=floa else: if predicate(): return - attempt += 1 time.sleep(check_interval) # Print the cause of the timeout predicate_source = "''''\n" + inspect.getsource(predicate) + "'''" logger.error("wait_until() failed. Predicate: {}".format(predicate_source)) - if attempt >= attempts: - raise AssertionError("Predicate {} not true after {} attempts".format(predicate_source, attempts)) - elif time.time() >= time_end: - raise AssertionError("Predicate {} not true after {} seconds".format(predicate_source, timeout)) - raise RuntimeError('Unreachable') + raise AssertionError("Predicate {} not true after {} seconds".format(predicate_source, timeout)) def sha256sum_file(filename):