merge bitcoin#24192: Fix feature_init intermittent issues

This commit is contained in:
Kittywhiskers Van Gogh 2022-01-31 10:19:32 +01:00
parent a6062445be
commit 6645cde0e7
No known key found for this signature in database
GPG Key ID: 30CD0C065E5C4AAD
2 changed files with 8 additions and 42 deletions

View File

@ -3,8 +3,6 @@
# Distributed under the MIT software license, see the accompanying # Distributed under the MIT software license, see the accompanying
# file COPYING or http://www.opensource.org/licenses/mit-license.php. # file COPYING or http://www.opensource.org/licenses/mit-license.php.
"""Stress tests related to node initialization.""" """Stress tests related to node initialization."""
import random
import time
import os import os
from pathlib import Path from pathlib import Path
@ -26,7 +24,6 @@ class InitStressTest(BitcoinTestFramework):
def run_test(self): def run_test(self):
""" """
- test terminating initialization after seeing a certain log line. - 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. - test removing certain essential files to test startup error paths.
""" """
# TODO: skip Windows for now since it isn't clear how to SIGTERM. # 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: for terminate_line in lines_to_terminate_after:
self.log.info(f"Starting node and will exit after line '{terminate_line}'") self.log.info(f"Starting node and will exit after line '{terminate_line}'")
node.start(extra_args=['-txindex=1']) with node.wait_for_debug_log([terminate_line], ignore_case=True):
node.start(extra_args=['-txindex=1'])
num_total_logs = node.wait_for_debug_log([terminate_line], ignore_case=True) self.log.debug("Terminating node after terminate line was found")
self.log.debug(f"Terminating node after {num_total_logs} log lines seen")
sigterm_node() sigterm_node()
check_clean_start() check_clean_start()
self.stop_node(0) 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") self.log.info("Test startup errors after removing certain essential files")
files_to_disturb = { files_to_disturb = {

View File

@ -442,7 +442,8 @@ class TestNode():
time.sleep(0.05) 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)) 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. Block until we see a particular debug log message fragment or until we exceed the timeout.
Return: Return:
@ -452,6 +453,8 @@ class TestNode():
prev_size = self.debug_log_bytes() prev_size = self.debug_log_bytes()
re_flags = re.MULTILINE | (re.IGNORECASE if ignore_case else 0) re_flags = re.MULTILINE | (re.IGNORECASE if ignore_case else 0)
yield
while True: while True:
found = True found = True
with open(self.debug_log_path, encoding='utf-8') as dl: with open(self.debug_log_path, encoding='utf-8') as dl:
@ -463,8 +466,7 @@ class TestNode():
found = False found = False
if found: if found:
num_logs = len(log.splitlines()) return
return num_logs
if time.time() >= time_end: if time.time() >= time_end:
print_log = " - " + "\n - ".join(log.splitlines()) print_log = " - " + "\n - ".join(log.splitlines())
@ -476,7 +478,6 @@ class TestNode():
self._raise_assertion_error( self._raise_assertion_error(
'Expected messages "{}" does not partially match log:\n\n{}\n\n'.format( 'Expected messages "{}" does not partially match log:\n\n{}\n\n'.format(
str(expected_msgs), print_log)) str(expected_msgs), print_log))
return -1 # useless return to satisfy linter
@contextlib.contextmanager @contextlib.contextmanager
def profile_with_perf(self, profile_name: str): def profile_with_perf(self, profile_name: str):