diff options
author | MarcoFalke <falke.marco@gmail.com> | 2019-08-21 08:21:54 -0400 |
---|---|---|
committer | MarcoFalke <falke.marco@gmail.com> | 2019-08-21 08:22:25 -0400 |
commit | 6dfa9efa3f558deaca0f01f673c79cce2b92a2b3 (patch) | |
tree | e79c4bc7f766698205a51e1d5db743f6350ca16d | |
parent | 01ebaa05a4872f3cf29745b3a51777cd5fe7af82 (diff) | |
parent | 6011c9d72d1df5c2cd09de6f85c21eb4f7eb1ba8 (diff) | |
download | bitcoin-6dfa9efa3f558deaca0f01f673c79cce2b92a2b3.tar.xz |
Merge #16656: test: fix rpc_setban.py race
6011c9d72d1df5c2cd09de6f85c21eb4f7eb1ba8 QA: fix rpc_setban.py race (Jonas Schnelli)
Pull request description:
The new `rpc_setban.py` test failes regularly on CIs due to a race between injecting the ban and testing the log "on the other side".
The problem is, that the test immediately after the `addnode` command on node0 checks for the `dropped (banned)` entry on node1 (without giving some time).
Adding a 2 seconds sleep seems to solve the race (I guess there is no better event-driven delay).
Example of a failed test: https://bitcoinbuilds.org/index.php?ansilog=bf743910-103f-4b54-9a97-960c471061bd.log#l2906
Top commit has no ACKs.
Tree-SHA512: 680f8ea3e5ddb07e93f824f1aeff4a459e25e6c14715a39fc7670e50506d7cf25925348672c5c2d8ba3e1243ccf5effbc2456bcd094fb96868349f8d26e008f1
-rwxr-xr-x | test/functional/rpc_setban.py | 2 | ||||
-rwxr-xr-x | test/functional/test_framework/test_node.py | 25 |
2 files changed, 18 insertions, 9 deletions
diff --git a/test/functional/rpc_setban.py b/test/functional/rpc_setban.py index a1a8196557..423741fd27 100755 --- a/test/functional/rpc_setban.py +++ b/test/functional/rpc_setban.py @@ -26,7 +26,7 @@ class SetBanTests(BitcoinTestFramework): self.nodes[1].setban("127.0.0.1", "add") # Node 0 should not be able to reconnect - with self.nodes[1].assert_debug_log(expected_msgs=['dropped (banned)\n']): + with self.nodes[1].assert_debug_log(expected_msgs=['dropped (banned)\n'],timeout=5): self.restart_node(1, []) self.nodes[0].addnode("127.0.0.1:" + str(p2p_port(1)), "onetry") diff --git a/test/functional/test_framework/test_node.py b/test/functional/test_framework/test_node.py index df027397d2..9667cf4ea4 100755 --- a/test/functional/test_framework/test_node.py +++ b/test/functional/test_framework/test_node.py @@ -307,7 +307,8 @@ class TestNode(): wait_until(self.is_node_stopped, timeout=timeout) @contextlib.contextmanager - def assert_debug_log(self, expected_msgs): + def assert_debug_log(self, expected_msgs, timeout=2): + time_end = time.time() + timeout debug_log = os.path.join(self.datadir, self.chain, 'debug.log') with open(debug_log, encoding='utf-8') as dl: dl.seek(0, 2) @@ -315,13 +316,21 @@ class TestNode(): try: yield finally: - with open(debug_log, encoding='utf-8') as dl: - dl.seek(prev_size) - log = dl.read() - print_log = " - " + "\n - ".join(log.splitlines()) - for expected_msg in expected_msgs: - if re.search(re.escape(expected_msg), log, flags=re.MULTILINE) is None: - self._raise_assertion_error('Expected message "{}" does not partially match log:\n\n{}\n\n'.format(expected_msg, print_log)) + while True: + found = True + with open(debug_log, encoding='utf-8') as dl: + dl.seek(prev_size) + log = dl.read() + print_log = " - " + "\n - ".join(log.splitlines()) + for expected_msg in expected_msgs: + if re.search(re.escape(expected_msg), log, flags=re.MULTILINE) is None: + found = False + if found: + return + if time.time() >= time_end: + break + time.sleep(0.05) + self._raise_assertion_error('Expected messages "{}" does not partially match log:\n\n{}\n\n'.format(str(expected_msgs), print_log)) @contextlib.contextmanager def assert_memory_usage_stable(self, *, increase_allowed=0.03): |