From 6011c9d72d1df5c2cd09de6f85c21eb4f7eb1ba8 Mon Sep 17 00:00:00 2001
From: Jonas Schnelli <dev@jonasschnelli.ch>
Date: Tue, 20 Aug 2019 14:31:00 +0200
Subject: [PATCH] QA: fix rpc_setban.py race

---
 test/functional/rpc_setban.py               |  2 +-
 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):