Repository: bitcoin/bitcoin
File: test/functional/test_framework/test_node.py (Python)

Code before:

        time_end = time.time() + timeout * self.timeout_factor
        prev_size = self.debug_log_size(encoding="utf-8")  # Must use same encoding that is used to read() below

        yield

        while True:
            found = True
            with open(self.debug_log_path, encoding="utf-8", errors="replace") as dl:
                dl.seek(prev_size)
                log = dl.read()
            print_log = " - " + "\n - ".join(log.splitlines())
            for unexpected_msg in unexpected_msgs:
                if re.search(re.escape(unexpected_msg), log, flags=re.MULTILINE):
                    self._raise_assertion_error('Unexpected message "{}" partially matches log:\n\n{}\n\n'.format(unexpected_msg, print_log))
            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 busy_wait_for_debug_log(self, expected_msgs, timeout=60):
        """
        Block until we see a particular debug log message fragment or until we exceed the timeout.
        Return:
            the number of log lines we encountered when matching
        """
        time_end = time.time() + timeout * self.timeout_factor
        prev_size = self.debug_log_size(mode="rb")  # Must use same mode that is used to read() below

        yield

        while True:
            found = True
            with open(self.debug_log_path, "rb") as dl:
                dl.seek(prev_size)
                log = dl.read()

            for expected_msg in expected_msgs:
                if expected_msg not in log:
                    found = False

            if found:
                return

            if time.time() >= time_end:

Review comment (suggestion):
this was weird before, it logged `print_log` which was created in different scope. Having `log` here is still weird, but I guess Python is weird.

nit: based on the docs, [`!r`](https://docs.python.org/3/library/functions.html#repr) might be more appropriate here:
```suggestion
        self._raise_assertion_error(f'Expected message(s) {expected_msgs!r} not found in log:\n\n{print_log(log)}\n\n')
```

Code after:
        remaining_expected = list(expected_msgs)

        time_end = time.time() + timeout * self.timeout_factor
        prev_size = self.debug_log_size(encoding="utf-8")  # Must use same encoding that is used to read() below

        def join_log(log):
            return " - " + "\n - ".join(log.splitlines())

        yield

        while True:
            with open(self.debug_log_path, encoding="utf-8", errors="replace") as dl:
                dl.seek(prev_size)
                log = dl.read()
            for unexpected_msg in unexpected_msgs:
                if unexpected_msg in log:
                    self._raise_assertion_error(f'Unexpected message "{unexpected_msg}" '
                                                f'found in log:\n\n{join_log(log)}\n\n')
            while remaining_expected and remaining_expected[-1] in log:
                remaining_expected.pop()
            if not remaining_expected:
                return
            if time.time() >= time_end:
                break
            time.sleep(0.05)
        remaining_expected = [e for e in remaining_expected if e not in log]
        self._raise_assertion_error(f'Expected message(s) {remaining_expected!s} '
                                    f'not found in log:\n\n{join_log(log)}\n\n')

    @contextlib.contextmanager
    def busy_wait_for_debug_log(self, expected_msgs, timeout=60):
        """
        Block until we see a particular debug log message fragment or until we exceed the timeout.
        """
        time_end = time.time() + timeout * self.timeout_factor
        prev_size = self.debug_log_size(mode="rb")  # Must use same mode that is used to read() below
        remaining_expected = list(expected_msgs)

        yield

        while True:
            with open(self.debug_log_path, "rb") as dl:
                dl.seek(prev_size)
                log = dl.read()

            while remaining_expected and remaining_expected[-1] in log:
                remaining_expected.pop()
            if not remaining_expected:
                return

            if time.time() >= time_end: