fix(tests): making test_read_only test less flaky

Author: StephenSorriaux

kazoo/protocol/connection.py

@@ -544,9 +544,9 @@ def zk_loop(self):
                 if retry(self._connect_loop, retry) is STOP_CONNECTING:
                     break
         except RetryFailedError:
-            self.logger.warning(
+            self.logger.exception(
                 "Failed connecting to Zookeeper "
-                "within the connection retry policy."
+                "within the connection retry policy:"
             )
         finally:
             self.connection_stopped.set()

kazoo/testing/common.py

@@ -221,8 +221,9 @@ def run(self):
         )
         self.process = subprocess.Popen(args=args)
         log.info(
-            "Started zookeeper process %s using args %s",
+            "Started zookeeper process %s on port %s using args %s",
             self.process.pid,
+            self.server_info.client_port,
             args,
         )
         self._running = True
@@ -304,12 +305,12 @@ def destroy(self):
 
         shutil.rmtree(self.working_path, True)
 
-    def get_logs(self):
+    def get_logs(self, num_lines=100):
         log_path = pathlib.Path(self.working_path, "zookeeper.log")
         if log_path.exists():
             log_file = log_path.open("r")
             lines = log_file.readlines()
-            return lines[-100:]
+            return lines[-num_lines:]
         return []
 
 

kazoo/testing/harness.py

@@ -210,7 +210,15 @@ def setup_zookeeper(self, **client_options):
         self.hosts = self.servers + namespace
         if "timeout" not in client_options:
             client_options["timeout"] = self.DEFAULT_CLIENT_TIMEOUT
+        retry_no_interrupt = client_options.pop("retry_no_interrupt", False)
+        if retry_no_interrupt:
+            from kazoo.retry import KazooRetry
+
+            conn_retry = KazooRetry(max_tries=-1, delay=0.2, max_delay=180)
         self.client = self._get_client(**client_options)
+        if retry_no_interrupt:
+            conn_retry.interrupt = None
+            self.client._connection.retry_sleeper = conn_retry.copy()
         self.client.start()
         self.client.ensure_path("/")
 

kazoo/tests/conftest.py

@@ -4,8 +4,10 @@
 
 
 def pytest_exception_interact(node, call, report):
-    if hasattr(node._testcase, "cluster"):
+    try:
         cluster = node._testcase.cluster
         log.error("Zookeeper cluster logs:")
         for logs in cluster.get_logs():
             log.error(logs)
+    except Exception:
+        log.exception("Cant get ZK logs:")

kazoo/tests/test__connection.py renamed to kazoo/tests/test_connection.py

@@ -1,4 +1,6 @@
 from collections import namedtuple, deque
+import logging
+
 import os
 import threading
 import time
@@ -18,8 +20,10 @@
 from kazoo.protocol.states import KazooState
 from kazoo.protocol.connection import _CONNECTION_DROP
 from kazoo.testing import KazooTestCase
-from kazoo.tests.util import wait
-from kazoo.tests.util import CI_ZK_VERSION
+from kazoo.tests.util import wait, CI_ZK_VERSION, CI
+
+
+log = logging.getLogger(__name__)
 
 
 class Delete(namedtuple("Delete", "path version")):
@@ -258,7 +262,7 @@ def back(state):
 class TestReadOnlyMode(KazooTestCase):
     def setUp(self):
         os.environ["ZOOKEEPER_LOCAL_SESSION_RO"] = "true"
-        self.setup_zookeeper(read_only=True)
+        self.setup_zookeeper(retry_no_interrupt=True)
         skip = False
         if CI_ZK_VERSION and CI_ZK_VERSION < (3, 4):
             skip = True
@@ -278,8 +282,15 @@ def tearDown(self):
     def test_read_only(self):
         from kazoo.exceptions import NotReadOnlyCallError
         from kazoo.protocol.states import KeeperState
+        from kazoo.retry import KazooRetry
 
-        client = self.client
+        time.sleep(15)
+        self.client.stop()
+        conn_retry = KazooRetry(max_tries=-1, delay=0.2, max_delay=180)
+        client = self._get_client(connection_retry=conn_retry, read_only=True)
+        # XXX: avoid the use of `interrupt`
+        conn_retry.interrupt = None
+        client._connection.retry_sleeper = conn_retry.copy()
         states = []
         ev = threading.Event()
 
@@ -289,6 +300,7 @@ def listen(state):
             if client.client_state == KeeperState.CONNECTED_RO:
                 ev.set()
 
+        client.start()
         try:
             # stopping both nodes at the same time
             # else the test seems flaky when on CI hosts
@@ -303,7 +315,13 @@ def listen(state):
                 thread.start()
             for thread in zk_stop_threads:
                 thread.join()
-            ev.wait(15)
+            client.stop()
+            client.start()
+            # the latest ZK node can take time to recover on the CI
+            time_to_wait = 30 if CI else 10
+            ev.wait(time_to_wait)
+            for line in self.cluster[0].get_logs(num_lines=250):
+                log.warning(line)
             assert ev.is_set()
             assert client.client_state == KeeperState.CONNECTED_RO
 

kazoo/tests/test_lock.py

@@ -511,7 +511,8 @@ def test_rw_lock(self):
 
             with self.condition:
                 while not self.active_thread:
-                    self.condition.wait()
+                    success = self.condition.wait(timeout=10)
+                    assert success
                 assert self.active_thread == contender
 
             assert lock.contenders() == remaining
@@ -521,7 +522,8 @@ def test_rw_lock(self):
 
             with self.condition:
                 while self.active_thread:
-                    self.condition.wait()
+                    success = self.condition.wait(timeout=10)
+                    assert success
 
         reader_thread.join()
         writer_thread.join()

pyproject.toml

@@ -21,6 +21,10 @@ extend-exclude = '''
 
 [tool.pytest.ini_options]
 addopts = "-ra -v"
+log_cli = true
+log_cli_date_format = "%Y-%m-%d %H:%M:%S"
+log_cli_format = "%(asctime)s %(levelname)s %(message)s"
+log_cli_level = "INFO"
 
 [tool.mypy]
 
@@ -114,11 +118,11 @@ module = [
     'kazoo.testing.common',
     'kazoo.testing.harness',
     'kazoo.tests.conftest',
-    'kazoo.tests.test__connection',
     'kazoo.tests.test_barrier',
     'kazoo.tests.test_build',
     'kazoo.tests.test_cache',
     'kazoo.tests.test_client',
+    'kazoo.tests.test_connection',
     'kazoo.tests.test_counter',
     'kazoo.tests.test_election',
     'kazoo.tests.test_eventlet_handler',

tox.ini

@@ -36,7 +36,7 @@ allowlist_externals =
 commands =
     sasl: {toxinidir}/init_krb5.sh {envtmpdir}/kerberos \
         {toxinidir}/ensure-zookeeper-env.sh \
-        pytest {posargs: -ra -v --cov-report=xml --cov=kazoo kazoo/tests}
+        pytest {posargs: -ra -v --cov-report=xml --cov=kazoo kazoo/tests/test_connection.py}
 
 [testenv:build]