Merge pull request #209 from dcermak/healthcheck-timeout

Healthcheck timeout

CHANGELOG.rst

@@ -6,6 +6,11 @@ Breaking changes:
 
 Improvements and new features:
 
+- Don't wait for crashed/stopped containers to become healthy (`gh#207
+  <https://github.com/dcermak/pytest_container/issues/207>`_)
+
+- Improve logging and error messages involving ``HEALTHCHECK``
+
 
 Documentation:
 
@@ -20,6 +25,7 @@ Breaking changes:
 
 
 Improvements and new features:
+
 - Add compatibility with podman 5
 
 

pytest_container/container.py

@@ -1157,13 +1157,18 @@ def _wait_for_container_to_become_healthy(self) -> None:
 
         if timeout is not None and timeout > timedelta(seconds=0):
             _logger.debug(
-                "Container has a healthcheck defined, will wait at most %s ms",
-                timeout,
+                "Container has a healthcheck defined, will wait at most %s s",
+                timeout.total_seconds(),
             )
             while True:
-                health = self.container_runtime.get_container_health(
+                inspect = self.container_runtime.inspect_container(
                     self._container_id
                 )
+                if not inspect.state.running:
+                    raise RuntimeError(
+                        f"Container {self._container_id} is not running, got {inspect.state.status}"
+                    )
+                health = inspect.state.health
                 _logger.debug("Container has the health status %s", health)
 
                 if health in (
@@ -1175,8 +1180,8 @@ def _wait_for_container_to_become_healthy(self) -> None:
                 if delta > timeout:
                     raise RuntimeError(
                         f"Container {self._container_id} did not become healthy within "
-                        f"{1000 * timeout.total_seconds()}ms, took {delta} and "
-                        f"state is {str(health)}"
+                        f"{timeout.total_seconds()}s, took "
+                        f"{delta.total_seconds()}s and state is {str(health)}"
                     )
                 time.sleep(max(0.5, timeout.total_seconds() / 10))
 

tests/test_healthcheck.py

@@ -1,10 +1,13 @@
 # pylint: disable=missing-function-docstring,missing-module-docstring
+import logging
+from datetime import datetime
 from datetime import timedelta
 from time import sleep
 from typing import Optional
 
 import pytest
 from pytest_container.container import ContainerData
+from pytest_container.container import ContainerLauncher
 from pytest_container.container import DerivedContainer
 from pytest_container.container import ImageFormat
 from pytest_container.runtime import ContainerHealth
@@ -47,6 +50,14 @@ def _failing_healthcheck_container(healtcheck_args: str) -> DerivedContainer:
     "--retries=2 --interval=2s"
 )
 
+CONTAINER_THAT_FAILS_TO_LAUNCH_WITH_FAILING_HEALTHCHECK = DerivedContainer(
+    base=LEAP_URL,
+    image_format=ImageFormat.DOCKER,
+    containerfile="""ENTRYPOINT ["/bin/false"]
+HEALTHCHECK --retries=5 --timeout=10s --interval=10s CMD false
+""",
+)
+
 
 @pytest.mark.parametrize(
     "container", [CONTAINER_WITH_HEALTHCHECK], indirect=True
@@ -152,3 +163,53 @@ def test_image_deriving_from_healthcheck_has_healthcheck(
         container_runtime.get_container_health(container.container_id)
         == ContainerHealth.HEALTHY
     )
+
+
+def test_container_that_doesnt_run_is_reported_unhealthy(
+    container_runtime: OciRuntimeBase, pytestconfig: pytest.Config
+) -> None:
+    before = datetime.now()
+    with pytest.raises(RuntimeError) as rt_err_ctx:
+        with ContainerLauncher(
+            container=CONTAINER_THAT_FAILS_TO_LAUNCH_WITH_FAILING_HEALTHCHECK,
+            container_runtime=container_runtime,
+            rootdir=pytestconfig.rootpath,
+        ) as launcher:
+            launcher.launch_container()
+            assert False, "The container must fail to launch"
+    after = datetime.now()
+
+    time_to_fail = after - before
+    assert time_to_fail < timedelta(
+        seconds=15
+    ), f"container must fail quickly (threshold 15s), but it took {time_to_fail.total_seconds()}"
+    assert "not running, got " in str(rt_err_ctx.value)
+
+
+def test_container_launcher_logs_correct_healthcheck_timeout(
+    container_runtime: OciRuntimeBase,
+    pytestconfig: pytest.Config,
+    caplog: pytest.LogCaptureFixture,
+) -> None:
+    caplog.set_level(logging.DEBUG)
+    ctr = DerivedContainer(
+        base=LEAP_URL,
+        image_format=ImageFormat.DOCKER,
+        containerfile="HEALTHCHECK --retries=5 --timeout=10s --interval=10s CMD true",
+    )
+    with ContainerLauncher(
+        container=ctr,
+        container_runtime=container_runtime,
+        rootdir=pytestconfig.rootpath,
+    ) as launcher:
+        launcher.launch_container()
+        assert launcher.container_data.inspect.config.healthcheck
+        timeout = (
+            launcher.container_data.inspect.config.healthcheck.max_wait_time
+        )
+        assert timeout == timedelta(seconds=60)
+
+    assert (
+        "Container has a healthcheck defined, will wait at most 60.0 s"
+        in caplog.text
+    )

tests/test_launcher.py

@@ -1,5 +1,6 @@
 # pylint: disable=missing-function-docstring,missing-module-docstring
 import os
+import re
 import subprocess
 import tempfile
 from contextlib import ExitStack
@@ -183,7 +184,13 @@ def test_launcher_fails_on_failing_healthcheck(
             launcher.launch_container()
             assert False, "This code must be unreachable"
 
-    assert "did not become healthy within" in str(runtime_err_ctx.value)
+    err_msg_regex = re.compile(
+        r"Container (\d|\w*) did not become healthy within (\d+\.\d+s), took (\d+.\d+s) and state is (\w+)"
+    )
+    err_msg_match = err_msg_regex.match(str(runtime_err_ctx.value))
+    assert (
+        err_msg_match
+    ), f"Error message '{str(runtime_err_ctx.value)}' does not match expected pattern {err_msg_regex}"
 
     # the container must not exist anymore
     err_msg = host.run_expect(