diff options
| author | MarcoFalke <falke.marco@gmail.com> | 2022-01-31 18:04:53 +0100 |
|---|---|---|
| committer | MarcoFalke <falke.marco@gmail.com> | 2022-01-31 18:05:01 +0100 |
| commit | 8f137e69caeb2a2ffe1aa930bd6fbc49cee4087c (patch) | |
| tree | 9d026772be9534b6b3828113e9e32c0c3e26d9f9 | |
| parent | 0ff13913287b3874e305535c78bc43b190217168 (diff) | |
| parent | fa7b07571f24b6def6effdd4cc1b96c7507bf959 (diff) | |
Merge bitcoin/bitcoin#24192: test: Fix feature_init intermittent issues
fa7b07571f24b6def6effdd4cc1b96c7507bf959 test: Fix feature_init intermittent issues (MarcoFalke)
fa4595deb334f14dac9ba481d786a823e0f0fde1 test: Remove random line number feature from feature_init.py (MarcoFalke)
Pull request description:
The test doesn't work currently because the log might be finalized before `wait_for_debug_log` is started, in which case it will assume the log is empty and fail to detect any line.
Fix this by calling `wait_for_debug_log` first. Fixes #24060.
Also, remove the "random line number" part of the test, because it doesn't really test anything novel. `wait_for_debug_log` is inherently racy, so will randomly terminate at the exact point or later. So the randomization is already sufficiently covered.
ACKs for top commit:
jamesob:
ACK https://github.com/bitcoin/bitcoin/pull/24192/commits/fa7b07571f24b6def6effdd4cc1b96c7507bf959
mzumsande:
Code Review ACK fa7b07571f24b6def6effdd4cc1b96c7507bf959
Tree-SHA512: f107a04926270a1d9ac8f53b6e5254566d1827ba7d27fd74f9ce909319f8794f8bd46da9c42256bf41b6df26c0bad8b9a0d54e4e148695189af09f31e3948330
| -rwxr-xr-x | test/functional/feature_init.py | 41 | ||||
| -rwxr-xr-x | test/functional/test_framework/test_node.py | 9 |
2 files changed, 8 insertions, 42 deletions
diff --git a/test/functional/feature_init.py b/test/functional/feature_init.py index 4b56b0c26b..dbd71a8b2d 100755 --- a/test/functional/feature_init.py +++ b/test/functional/feature_init.py @@ -3,8 +3,6 @@ # Distributed under the MIT software license, see the accompanying # file COPYING or http://www.opensource.org/licenses/mit-license.php. """Stress tests related to node initialization.""" -import random -import time import os from pathlib import Path @@ -26,7 +24,6 @@ class InitStressTest(BitcoinTestFramework): def run_test(self): """ - test terminating initialization after seeing a certain log line. - - test terminating init after seeing a random number of log lines. - test removing certain essential files to test startup error paths. """ # TODO: skip Windows for now since it isn't clear how to SIGTERM. @@ -76,46 +73,14 @@ class InitStressTest(BitcoinTestFramework): for terminate_line in lines_to_terminate_after: self.log.info(f"Starting node and will exit after line '{terminate_line}'") - node.start(extra_args=['-txindex=1']) - - num_total_logs = node.wait_for_debug_log([terminate_line], ignore_case=True) - self.log.debug(f"Terminating node after {num_total_logs} log lines seen") + with node.wait_for_debug_log([terminate_line], ignore_case=True): + node.start(extra_args=['-txindex=1']) + self.log.debug("Terminating node after terminate line was found") sigterm_node() check_clean_start() self.stop_node(0) - self.log.info( - f"Terminate at some random point in the init process (max logs: {num_total_logs})") - - for _ in range(40): - num_logs = len(Path(node.debug_log_path).read_text().splitlines()) - additional_lines = random.randint(1, num_total_logs) - self.log.debug(f"Starting node and will exit after {additional_lines} lines") - node.start(extra_args=['-txindex=1']) - logfile = open(node.debug_log_path, 'rb') - - MAX_SECS_TO_WAIT = 10 - start = time.time() - num_lines = 0 - - while True: - line = logfile.readline() - if line: - num_lines += 1 - - if num_lines >= (num_logs + additional_lines) or \ - (time.time() - start) > MAX_SECS_TO_WAIT: - self.log.debug(f"Terminating node after {num_lines} log lines seen") - sigterm_node() - break - - if node.process.poll() is not None: - raise AssertionError("node failed to start") - - check_clean_start() - self.stop_node(0) - self.log.info("Test startup errors after removing certain essential files") files_to_disturb = { diff --git a/test/functional/test_framework/test_node.py b/test/functional/test_framework/test_node.py index 0b9154a030..289e83579b 100755 --- a/test/functional/test_framework/test_node.py +++ b/test/functional/test_framework/test_node.py @@ -422,7 +422,8 @@ class TestNode(): 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)) - def wait_for_debug_log(self, expected_msgs, timeout=10, ignore_case=False) -> int: + @contextlib.contextmanager + def wait_for_debug_log(self, expected_msgs, timeout=60, ignore_case=False): """ Block until we see a particular debug log message fragment or until we exceed the timeout. Return: @@ -432,6 +433,8 @@ class TestNode(): prev_size = self.debug_log_bytes() re_flags = re.MULTILINE | (re.IGNORECASE if ignore_case else 0) + yield + while True: found = True with open(self.debug_log_path, encoding='utf-8') as dl: @@ -443,8 +446,7 @@ class TestNode(): found = False if found: - num_logs = len(log.splitlines()) - return num_logs + return if time.time() >= time_end: print_log = " - " + "\n - ".join(log.splitlines()) @@ -456,7 +458,6 @@ class TestNode(): self._raise_assertion_error( 'Expected messages "{}" does not partially match log:\n\n{}\n\n'.format( str(expected_msgs), print_log)) - return -1 # useless return to satisfy linter @contextlib.contextmanager def profile_with_perf(self, profile_name: str): |