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

Code before:

    @contextlib.contextmanager
    def assert_debug_log(self, expected_msgs, unexpected_msgs=None, timeout=2):
        if unexpected_msgs is None:
            unexpected_msgs = []
        assert_equal(type(expected_msgs), list)
        assert_equal(type(unexpected_msgs), list)

        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:

Review comment (bug):
what's the reason for regex iteration above and here if we're just escaping it anyway? We're not doing it in `busy_wait_for_debug_log`
I have added
```python
            found = []
            for i, expected_msg in enumerate(expected_msgs):
                if re.search(re.escape(expected_msg), log, flags=re.MULTILINE):
                    found.append(i)
            found2 = [i for i, m in enumerate(expected_msgs) if m in log]
            assert found == found2, f"Mismatch: {found} != {found2}"
```
and ran the whole suite and it seems to be the same, maybe we can simplify it.
Note that `found2` should likely be a `set` instead of a list, otherwise comparing the sizes may not make sense. It also helps with the `in` condition for the remaining values.

Code after:

    @contextlib.contextmanager
    def assert_debug_log(self, expected_msgs, unexpected_msgs=None, timeout=2):
        if unexpected_msgs is None:
            unexpected_msgs = []
        assert_equal(type(expected_msgs), list)
        assert_equal(type(unexpected_msgs), list)
        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()