fix(hooks): retry a command whose replaced container is still around

alakazam.py

@@ -61,8 +61,14 @@ GROUP_PATH = None  # path this run was invoked with, either an instance file or
 HIDE_SECRETS = False  # keep secret values out of the output, for runs whose logs are archived
 ABRA_DIR = None  # path to the abra data directory
 FETCH_MAX_AGE = 3600 # seconds; recipe repos are refetched at most once per hour
-ABRA_RETRIES = 6 # number of attempts per abra command that failed to reach the server
+ABRA_RETRIES = 8 # number of attempts per abra command that failed for a reason worth retrying
 ABRA_RETRY_DELAY = 2 # seconds before the first retry, doubled for every further one
+# lower case markers in the abra output for an app whose replaced container has not gone away yet,
+# which leaves abra unable to tell which one a command is meant for
+AMBIGUOUS_CONTAINER_ERRORS = (
+    "ambiguous container list",
+    "expected 1 container but found",
+)
 # lower case markers in the abra output that indicate an unreachable server instead of a failed operation
 CONNECTION_ERRORS = (
     "error during connect",
@@ -706,6 +712,27 @@ def is_connection_error(output: str) -> bool:
     return any(error in output.lower() for error in CONNECTION_ERRORS)
 
 
+def get_retry_reason(output: str) -> Optional[str]:
+    """
+    Names the transient condition an abra output shows, or nothing when the failure is a real one.
+
+    Both conditions leave the server untouched: an unreachable server never ran the command, and an
+    ambiguous container list is decided before the command is handed over. Retrying is therefore
+    safe even for a command that would not survive being run twice.
+
+    Args:
+        output (str): The combined stdout and stderr of the abra command
+
+    Returns:
+        str: What went wrong, phrased for the retry message, or None if it is worth no retry
+    """
+    if is_connection_error(output):
+        return "failed to reach the server"
+    if any(error in output.lower() for error in AMBIGUOUS_CONTAINER_ERRORS):
+        return "found more than one container, the replaced one has not gone away yet"
+    return None
+
+
 def run_streamed(command: List[str]) -> subprocess.CompletedProcess:
     """
     Runs a command and echoes its output line by line while it is still running.
@@ -764,12 +791,13 @@ def abra(*args: str, machine_output: bool = False, ignore_error: bool = False, s
         process = run_streamed(command) if stream else subprocess.run(command, capture_output=True)
         if not process.returncode or attempt == ABRA_RETRIES:
             break
-        if not is_connection_error(process.stdout.decode() + process.stderr.decode()):
+        reason = get_retry_reason(process.stdout.decode() + process.stderr.decode())
+        if not reason:
             break
         # back off exponentially: a server that drops connections during the ssh handshake is
         # usually throttling, and retrying every couple of seconds keeps it throttling
         delay = ABRA_RETRY_DELAY * 2 ** (attempt - 1)
-        logging.warning(f"attempt {attempt}/{ABRA_RETRIES} of '{' '.join(command)}' failed to reach the server, retry in {delay}s")
+        logging.warning(f"attempt {attempt}/{ABRA_RETRIES} of '{' '.join(command)}' {reason}, retry in {delay}s")
         sleep(delay)
     if process.stderr and ignore_error and not quiet:
         logging.warning(process.stderr.decode())

tests/test_retry.py

@@ -1,5 +1,6 @@
 """Tests for which abra failures may be retried."""
 
+import logging
 import os
 import sys
 
@@ -9,7 +10,7 @@ import pytest
 sys.path.insert(0, os.path.dirname(os.path.dirname(os.path.abspath(__file__))))
 
 import alakazam
-from alakazam import abra, is_connection_error
+from alakazam import abra, get_retry_reason, is_connection_error
 
 
 class FakeProcess:
@@ -21,19 +22,22 @@ class FakeProcess:
 
 UNREACHABLE = b"FATA error during connect: kex_exchange_identification: Connection closed by remote host"
 REJECTED = b"FATA login.a.org is still deployed"
+AMBIGUOUS = (b"WARN ambiguous container list received, prompting for input\n"
+             b"? which container are you looking for?\nFATA EOF")
+
+
+@pytest.fixture
+def runs(monkeypatch):
+    """Hands out a prepared result per abra call and records what was slept between them."""
+    calls = {"results": [], "slept": []}
+    monkeypatch.setattr(alakazam, "sleep", calls["slept"].append)
+    monkeypatch.setattr(alakazam.subprocess, "run", lambda cmd, capture_output: calls["results"].pop(0))
+    return calls
 
 
 class TestRetryLoop:
     """A server that drops the ssh handshake is usually throttling, so the retries have to spread out."""
 
-    @pytest.fixture
-    def runs(self, monkeypatch):
-        calls = {"results": [], "slept": []}
-        monkeypatch.setattr(alakazam, "sleep", calls["slept"].append)
-        monkeypatch.setattr(alakazam.subprocess, "run",
-                            lambda cmd, capture_output: calls["results"].pop(0))
-        return calls
-
     def test_a_successful_command_does_not_retry(self, runs):
         runs["results"] = [FakeProcess(0)]
         abra("app", "ls")
@@ -83,3 +87,35 @@ class TestConnectionErrors:
     ])
     def test_operational_failures_are_not_retried(self, output):
         assert not is_connection_error(output)
+
+
+class TestAmbiguousContainer:
+    """
+    An app that was just updated keeps its replaced container for a while, and abra then cannot
+    tell which of the two a command is meant for. It asks, and a run without a terminal ends on EOF.
+    """
+
+    @pytest.mark.parametrize("output", [
+        "WARN ambiguous container list received, prompting for input\nFATA EOF",
+        "FATA expected 1 container but found 2: files_app.1.pxo3 (created About a minute ago)",
+    ])
+    def test_it_is_worth_another_attempt(self, output):
+        assert get_retry_reason(output) == ("found more than one container, "
+                                            "the replaced one has not gone away yet")
+
+    def test_an_unreachable_server_keeps_its_own_reason(self):
+        assert get_retry_reason("kex_exchange_identification") == "failed to reach the server"
+
+    def test_a_rejected_operation_is_worth_none(self):
+        assert get_retry_reason("FATA login.a.org is still deployed") is None
+
+    def test_the_command_is_repeated_until_one_container_is_left(self, runs):
+        runs["results"] = [FakeProcess(1, AMBIGUOUS), FakeProcess(1, AMBIGUOUS), FakeProcess(0)]
+        abra("app", "cmd", "-T", "files.a.org", "app", "--", "run_occ", "upgrade")
+        assert runs["slept"] == [alakazam.ABRA_RETRY_DELAY, alakazam.ABRA_RETRY_DELAY * 2]
+
+    def test_the_reason_is_reported(self, runs, caplog):
+        runs["results"] = [FakeProcess(1, AMBIGUOUS), FakeProcess(0)]
+        with caplog.at_level(logging.WARNING):
+            abra("app", "cmd", "-T", "files.a.org", "app", "--", "run_occ", "upgrade")
+        assert "the replaced one has not gone away yet" in caplog.text