From 6bb3e54578ad5830ec785b9b26448222a84787a7 Mon Sep 17 00:00:00 2001 From: MarcoFalke Date: Sun, 3 May 2020 08:58:48 -0400 Subject: [PATCH] Merge #18617: test: add factor option to adjust test timeouts 2742c3428633b6ceaab6714635dc3adb74bf121b test: add factor option to adjust test timeouts (Harris) Pull request description: This PR adds a new option **factor** that can be used to adjust timeouts in various functional tests. Several timeouts and functions from `authproxy`, `mininode`, `test_node` and `util` have been adapted to use this option. The factor-option definition is located in `test_framework.py`. Fixes https://github.com/bitcoin/bitcoin/issues/18266 Also Fixes https://github.com/bitcoin/bitcoin/issues/18834 ACKs for top commit: MarcoFalke: Thanks! ACK 2742c3428633b6ceaab6714635dc3adb74bf121b Tree-SHA512: 6d8421933ba2ac1b7db00b70cf2bc242d9842c48121c11aadc30b0985c4a174c86a127d6402d0cd73b993559d60d4f747872d21f9510cf4806e008349780d3ef --- test/functional/test_framework/mininode.py | 31 ++++++++++--------- .../test_framework/test_framework.py | 4 +++ test/functional/test_framework/test_node.py | 9 +++--- test/functional/test_framework/util.py | 5 +-- 4 files changed, 28 insertions(+), 21 deletions(-) diff --git a/test/functional/test_framework/mininode.py b/test/functional/test_framework/mininode.py index 8ec215f288..704b13a138 100755 --- a/test/functional/test_framework/mininode.py +++ b/test/functional/test_framework/mininode.py @@ -22,7 +22,6 @@ from io import BytesIO import logging import struct import sys -import time import threading from test_framework.messages import ( @@ -155,8 +154,9 @@ class P2PConnection(asyncio.Protocol): def is_connected(self): return self._transport is not None - def peer_connect(self, dstaddr, dstport, *, net, uacomment=None): + def peer_connect(self, dstaddr, dstport, *, net, factor, uacomment=None): assert not self.is_connected + self.factor = factor self.dstaddr = dstaddr self.dstport = dstport # The initial message to send after the connection was made: @@ -440,11 +440,12 @@ class P2PInterface(P2PConnection): # Connection helper methods + def wait_until(self, test_function, timeout): + wait_until(test_function, timeout=timeout, lock=mininode_lock, factor=self.factor) + def wait_for_disconnect(self, timeout=60): test_function = lambda: not self.is_connected - wait_until(test_function, timeout=timeout, lock=mininode_lock) - # This is a hack. The related issues should be fixed by bitcoin 14119 and 14457. - time.sleep(1) + self.wait_until(test_function, timeout=timeout) # Message receiving helper methods @@ -455,14 +456,14 @@ class P2PInterface(P2PConnection): return False return self.last_message['tx'].tx.rehash() == txid - wait_until(test_function, timeout=timeout, lock=mininode_lock) + self.wait_until(test_function, timeout=timeout) def wait_for_block(self, blockhash, timeout=60): def test_function(): assert self.is_connected return self.last_message.get("block") and self.last_message["block"].block.rehash() == blockhash - wait_until(test_function, timeout=timeout, lock=mininode_lock) + self.wait_until(test_function, timeout=timeout) def wait_for_header(self, blockhash, timeout=60): def test_function(): @@ -472,7 +473,7 @@ class P2PInterface(P2PConnection): return False return last_headers.headers[0].rehash() == blockhash - wait_until(test_function, timeout=timeout, lock=mininode_lock) + self.wait_until(test_function, timeout=timeout) def wait_for_getdata(self, timeout=60): """Waits for a getdata message. @@ -486,7 +487,7 @@ class P2PInterface(P2PConnection): assert self.is_connected return self.last_message.get("getdata") - wait_until(test_function, timeout=timeout, lock=mininode_lock) + self.wait_until(test_function, timeout=timeout) def wait_for_getheaders(self, timeout=60): """Waits for a getheaders message. @@ -501,7 +502,7 @@ class P2PInterface(P2PConnection): return self.last_message.get("getheaders2") if self.nServices & NODE_HEADERS_COMPRESSED \ else self.last_message.get("getheaders") - wait_until(test_function, timeout=timeout, lock=mininode_lock) + self.wait_until(test_function, timeout=timeout) # TODO: enable when p2p_filter.py is backported # def wait_for_inv(self, expected_inv, timeout=60): @@ -515,13 +516,13 @@ class P2PInterface(P2PConnection): # self.last_message["inv"].inv[0].type == expected_inv[0].type and \ # self.last_message["inv"].inv[0].hash == expected_inv[0].hash - # wait_until(test_function, timeout=timeout, lock=mininode_lock) + # self.wait_until(test_function, timeout=timeout) def wait_for_verack(self, timeout=60): def test_function(): return "verack" in self.last_message - wait_until(test_function, timeout=timeout, lock=mininode_lock) + self.wait_until(test_function, timeout=timeout) # Message sending helper functions @@ -537,7 +538,7 @@ class P2PInterface(P2PConnection): assert self.is_connected return self.last_message.get("pong") and self.last_message["pong"].nonce == self.ping_counter - wait_until(test_function, timeout=timeout, lock=mininode_lock) + self.wait_until(test_function, timeout=timeout) self.ping_counter += 1 @@ -666,7 +667,7 @@ class P2PDataStore(P2PInterface): self.send_message(msg_block(block=b)) else: self.send_message(msg_headers([CBlockHeader(block) for block in blocks])) - wait_until(lambda: blocks[-1].sha256 in self.getdata_requests, timeout=timeout, lock=mininode_lock) + self.wait_until(lambda: blocks[-1].sha256 in self.getdata_requests, timeout=timeout) if expect_disconnect: self.wait_for_disconnect() @@ -674,7 +675,7 @@ class P2PDataStore(P2PInterface): self.sync_with_ping() if success: - wait_until(lambda: node.getbestblockhash() == blocks[-1].hash, timeout=timeout) + self.wait_until(lambda: node.getbestblockhash() == blocks[-1].hash, timeout=timeout) else: assert node.getbestblockhash() != blocks[-1].hash diff --git a/test/functional/test_framework/test_framework.py b/test/functional/test_framework/test_framework.py index 4f57a2df45..38743f6193 100755 --- a/test/functional/test_framework/test_framework.py +++ b/test/functional/test_framework/test_framework.py @@ -123,6 +123,7 @@ class BitcoinTestFramework(metaclass=BitcoinTestMetaClass): self.extra_args_from_options = [] self.set_test_params() self.parse_args() + self.rpc_timeout = int(self.rpc_timeout * self.options.factor) # optionally, increase timeout by a factor def main(self): """Main function. This should not be overridden by the subclass test scripts.""" @@ -188,6 +189,7 @@ class BitcoinTestFramework(metaclass=BitcoinTestMetaClass): help="run nodes under the valgrind memory error detector: expect at least a ~10x slowdown, valgrind 3.14 or later required") parser.add_argument("--randomseed", type=int, help="set a random seed for deterministically reproducing a previous test run") + parser.add_argument('--factor', type=float, default=1.0, help='adjust test timeouts by a factor') self.add_options(parser) # Running TestShell in a Jupyter notebook causes an additional -f argument # To keep TestShell from failing with an "unrecognized argument" error, we add a dummy "-f" argument @@ -440,6 +442,7 @@ class BitcoinTestFramework(metaclass=BitcoinTestMetaClass): chain=self.chain, rpchost=rpchost, timewait=self.rpc_timeout, + factor=self.options.factor, bitcoind=binary[i], bitcoin_cli=self.options.bitcoincli, mocktime=self.mocktime, @@ -613,6 +616,7 @@ class BitcoinTestFramework(metaclass=BitcoinTestMetaClass): extra_args_from_options=self.extra_args_from_options, rpchost=None, timewait=self.rpc_timeout, + factor=self.options.factor, bitcoind=self.options.bitcoind, bitcoin_cli=self.options.bitcoincli, mocktime=self.mocktime, diff --git a/test/functional/test_framework/test_node.py b/test/functional/test_framework/test_node.py index 1ab88eb6ec..ab3b203c13 100755 --- a/test/functional/test_framework/test_node.py +++ b/test/functional/test_framework/test_node.py @@ -62,7 +62,7 @@ class TestNode(): To make things easier for the test writer, any unrecognised messages will be dispatched to the RPC connection.""" - def __init__(self, i, datadir, extra_args_from_options, *, chain, rpchost, timewait, bitcoind, bitcoin_cli, mocktime, coverage_dir, cwd, extra_conf=None, extra_args=None, use_cli=False, start_perf=False, use_valgrind=False): + def __init__(self, i, datadir, extra_args_from_options, *, chain, rpchost, timewait, factor, bitcoind, bitcoin_cli, mocktime, coverage_dir, cwd, extra_conf=None, extra_args=None, use_cli=False, start_perf=False, use_valgrind=False): """ Kwargs: start_perf (bool): If True, begin profiling the node with `perf` as soon as @@ -131,6 +131,7 @@ class TestNode(): self.perf_subprocesses = {} self.p2ps = [] + self.factor = factor AddressKeyPair = collections.namedtuple('AddressKeyPair', ['address', 'key']) PRIV_KEYS = [ @@ -337,13 +338,13 @@ class TestNode(): return True def wait_until_stopped(self, timeout=BITCOIND_PROC_WAIT_TIMEOUT): - wait_until(self.is_node_stopped, timeout=timeout) + wait_until(self.is_node_stopped, timeout=timeout, factor=self.factor) @contextlib.contextmanager def assert_debug_log(self, expected_msgs, unexpected_msgs=None, timeout=2): if unexpected_msgs is None: unexpected_msgs = [] - time_end = time.time() + timeout + time_end = time.time() + timeout * self.factor chain = get_chain_folder(self.datadir, self.chain) debug_log = os.path.join(self.datadir, chain, 'debug.log') with open(debug_log, encoding='utf-8') as dl: @@ -501,7 +502,7 @@ class TestNode(): if 'dstaddr' not in kwargs: kwargs['dstaddr'] = '127.0.0.1' - p2p_conn.peer_connect(**kwargs, net=self.chain)() + p2p_conn.peer_connect(**kwargs, net=self.chain, factor=self.factor)() self.p2ps.append(p2p_conn) if wait_for_verack: p2p_conn.wait_for_verack() diff --git a/test/functional/test_framework/util.py b/test/functional/test_framework/util.py index 832e0c6088..3a43c93fcf 100644 --- a/test/functional/test_framework/util.py +++ b/test/functional/test_framework/util.py @@ -227,9 +227,10 @@ def str_to_b64str(string): def satoshi_round(amount): return Decimal(amount).quantize(Decimal('0.00000001'), rounding=ROUND_DOWN) -def wait_until(predicate, *, attempts=float('inf'), timeout=float('inf'), sleep=0.05, lock=None, do_assert=True, allow_exception=False): +def wait_until(predicate, *, attempts=float('inf'), timeout=float('inf'), sleep=0.05, factor=1.0, lock=None, do_assert=True, allow_exception=False): if attempts == float('inf') and timeout == float('inf'): timeout = 60 + timeout = timeout * factor attempt = 0 timeout *= Options.timeout_scale time_end = time.time() + timeout @@ -292,7 +293,7 @@ def get_rpc_proxy(url, node_number, *, timeout=None, coveragedir=None): """ proxy_kwargs = {} if timeout is not None: - proxy_kwargs['timeout'] = timeout + proxy_kwargs['timeout'] = int(timeout) proxy = AuthServiceProxy(url, **proxy_kwargs) proxy.url = url # store URL on proxy for info