feat(upgrade): report the run in three buckets

README.md

@@ -147,6 +147,10 @@ To update all instances:
 
 1. **Update Environment Files**: `alakazam example.com.yml config` to refresh .env files. It's a good practice to keep these files under version control (e.g., in a Git repository at `~/.abra/example.com`) and review changes with `git diff` before proceeding.
 2. **Upgrade Applications**: `alakazam example.com.yml upgrade` to update all applications.
+    - an app that abra refuses and an app that does not become healthy both end the run non-zero,
+      the apps beside them are still upgraded and still get their hooks
+    - a failing upgrade hook is reported but does not end the run, so that the hooks can be fixed
+      one at a time
 
 ### Rotate Secrets
 

alakazam.py

@@ -1469,7 +1469,7 @@ def insert_secrets_from_conf(domain: str, app_config: Dict[str, Any]) -> None:
                 insert_secret(domain, secret_name, secret)
 
 
-def run_local_script(tokens: List[str], app_domain: str, server: str, instance_domain: str, dry_run: bool = False, strict: bool = False) -> None:
+def run_local_script(tokens: List[str], app_domain: str, server: str, instance_domain: str, dry_run: bool = False, strict: bool = False) -> Optional[str]:
     """
     Run a local script hook. Relative paths are resolved against ROOT_PATH for execution. Logs an error and returns early if the script is not executable.
 
@@ -1481,6 +1481,9 @@ def run_local_script(tokens: List[str], app_domain: str, server: str, instance_d
         dry_run (bool): If True, prints the command but does not execute it.
         strict (bool): Abort on a non-executable script or a non-zero exit code instead of only logging it.
 
+    Returns:
+        str: Why the script failed, or None when it ran through
+
     Raises:
         click.ClickException: If the script is not executable or exits non-zero and strict is set
     """
@@ -1494,16 +1497,18 @@ def run_local_script(tokens: List[str], app_domain: str, server: str, instance_d
         if strict:
             raise click.ClickException(f"script '{cmd_display}' failed for {app_domain}: {message}")
         logging.error(message)
-        return
+        return message
     if dry_run:
-        return
+        return None
     # the script may print a secret it just created, so its output is captured and dropped
     result = subprocess.run([str(script_path)] + args, env=env, capture_output=HIDE_SECRETS)
     if result.returncode != 0:
         message = f"Script '{cmd_display}' exited with code {result.returncode}"
         if strict:
             raise click.ClickException(f"script '{cmd_display}' failed for {app_domain}: {message}")
-        logging.warning(message)
+        logging.error(message)
+        return message
+    return None
 
 
 def run_secret_hooks(domain: str, app_config: Dict[str, Any], instance_domain: str = "", strict: bool = False) -> None:
@@ -1759,7 +1764,7 @@ def run_readiness_hooks(domain: str, app_config: Dict[str, Any]) -> None:
         run_readiness_hook(domain, hook)
 
 
-def execute_cmds(app_config: Dict[str, Any], commands: Tuple[str] = tuple(), pre_upgrade: bool = False, initial: bool = False, deploy: bool = False, upgrade: bool = False, dry_run: bool = False, chaos: bool = False, strict: bool = False, instance_domain: str = "") -> None:
+def execute_cmds(app_config: Dict[str, Any], commands: Tuple[str] = tuple(), pre_upgrade: bool = False, initial: bool = False, deploy: bool = False, upgrade: bool = False, dry_run: bool = False, chaos: bool = False, strict: bool = False, instance_domain: str = "") -> List[str]:
     """
     Execute post-deployment commands for an application based on the provided configuration.
     This can include running scripts or commands inside the application's environment.
@@ -1777,7 +1782,8 @@ def execute_cmds(app_config: Dict[str, Any], commands: Tuple[str] = tuple(), pre
         instance_domain (str): The instance domain, used to set ALAKAZAM_INSTANCE_DOMAIN for script hooks.
 
     Returns:
-        None
+        list: The commands that failed, empty when all of them ran through. Always empty with
+            strict, which ends on the first failure instead of collecting it.
 
     Raises:
         click.ClickException: If a command fails and strict is set
@@ -1799,6 +1805,7 @@ def execute_cmds(app_config: Dict[str, Any], commands: Tuple[str] = tuple(), pre
     chaos_flag = ""
     if chaos:
         chaos_flag = "-C"
+    failed = []
     for kind, cmds in groups:
         # a real run has the deployment output between the kinds to tell them apart, a dry run
         # prints them back to back and needs saying which side of the deployment each one is on
@@ -1808,15 +1815,22 @@ def execute_cmds(app_config: Dict[str, Any], commands: Tuple[str] = tuple(), pre
             tokens = cmd.split()
             container = tokens[0]
             if container == "script" and len(tokens) >= 2 and resolve_path(tokens[1]).exists():
-                run_local_script(tokens, domain, server, instance_domain, dry_run, strict)
+                if reason := run_local_script(tokens, domain, server, instance_domain, dry_run, strict):
+                    failed.append(cmd)
                 continue
             print(f"Run '{cmd}' in {domain}:{container}", flush=True)
             if dry_run:
                 continue
             try:
-                abra(*build_app_cmd(domain, cmd, chaos_flag), ignore_error=not strict, stream=True)
+                # the error is raised here even without strict, so that a failure can be reported
+                # rather than only showing up in the streamed output
+                abra(*build_app_cmd(domain, cmd, chaos_flag), stream=True)
             except RuntimeError as e:
-                raise click.ClickException(f"command '{cmd}' failed for {domain}: {e}")
+                if strict:
+                    raise click.ClickException(f"command '{cmd}' failed for {domain}: {e}")
+                logging.error(f"command '{cmd}' failed for {domain}: {e}")
+                failed.append(cmd)
+    return failed
 
 
 @click.group(context_settings={"help_option_names": ['-h', '--help']})
@@ -2091,6 +2105,66 @@ def deploy_apps(instance_apps: Dict[str, List[List]], execute_hooks: bool = Fals
             execute_cmds(app_config, deploy=True, instance_domain=instance)
 
 
+def run_upgrade_hooks(upgraded: List[Tuple[str, Dict[str, Any], str]], unhealthy: List[str]) -> List[Tuple[str, str]]:
+    """
+    Runs the upgrade hooks of every app that came back healthy and collects the ones that failed.
+
+    An app that never became healthy is left out: its hook would reach a container that is not
+    there, and the failure would say nothing beyond what the health check already said. A failing
+    hook is collected rather than raised, so that the apps behind it still get theirs.
+
+    Args:
+        upgraded (list): Tuples of app name, app configuration and instance domain
+        unhealthy (list): App domains whose services did not become healthy
+
+    Returns:
+        list: Tuples of app domain and the hook command that failed
+    """
+    failures = []
+    for app, app_config, instance_domain in upgraded:
+        domain = app_config.get('app_domain')
+        if domain in unhealthy:
+            logging.warning(f"{domain} is not healthy, its upgrade hooks are left out")
+            continue
+        logging.info(f"execute commands for {domain}")
+        failures += [(domain, cmd) for cmd in
+                     execute_cmds(app_config, upgrade=True, instance_domain=instance_domain)]
+    return failures
+
+
+def report_upgrade_run(total: int, failed: List[str], unhealthy: List[str],
+                       hook_failures: List[Tuple[str, str]]) -> None:
+    """
+    Reports what an upgrade run could not finish, and ends it when something needs a person.
+
+    An app that was refused and an app that never became healthy both leave the environment in a
+    state nobody asked for, so they end the run non-zero. A failing hook is reported only: hooks
+    still fail for reasons that are not failures, such as mariadb-upgrade refusing an already
+    upgraded database, and a verdict on them has to wait until those are sorted out.
+
+    Args:
+        total (int): How many apps the run set out to upgrade
+        failed (list): App domains abra refused to upgrade
+        unhealthy (list): App domains whose services did not become healthy
+        hook_failures (list): Tuples of app domain and the hook command that failed
+
+    Raises:
+        click.ClickException: If any app failed to upgrade or never became healthy
+    """
+    if hook_failures:
+        listed = ", ".join(f"{domain} '{cmd}'" for domain, cmd in hook_failures)
+        logging.error(f"{len(hook_failures)} upgrade hook(s) failed, "
+                      f"which does not end this run: {listed}")
+    problems = []
+    if failed:
+        problems.append(f"{len(failed)} of {total} app(s) failed to upgrade: {', '.join(failed)}")
+    if unhealthy:
+        problems.append(f"{len(unhealthy)} of {total} app(s) did not become healthy: "
+                        f"{', '.join(unhealthy)}")
+    if problems:
+        raise click.ClickException("\n".join(problems))
+
+
 @cli.command()
 @click.option('recipes', '-r', '--recipe', multiple=True, metavar='<RecipeName>', help='Filter for selcted recipes, this option can be specified multiple times.')
 @click.option('-e', '--execute-hooks', is_flag=True, help='run post-upgrade commands.')
@@ -2207,25 +2281,24 @@ def upgrade(recipes: Tuple[str], execute_hooks: bool, skip_pre_upgrade_hooks: bo
                 failed.append(app_domain)
                 continue
             upgraded.append((app, app_config, instance_domain))
-        problems = []
-        if failed:
-            problems.append(
-                f"{len(failed)} of {len(upgrade_cmds)} app(s) failed to upgrade: {', '.join(failed)}")
+        unhealthy, hook_failures = [], []
         if upgraded:
             try:
                 # the deployments were started without waiting for each other, so the services are
                 # still settling here and a hook would reach a container that is not up again yet
-                wait_for_healthy_apps(tuple({app for app, *_ in upgraded}), timeout, settle=settle)
+                pending = get_unhealthy_apps(tuple({app for app, *_ in upgraded}), timeout,
+                                             settle=settle)
+                unhealthy = sorted({domain for domain, _ in pending})
+                if pending:
+                    logging.error(f"{len(pending)} service(s) still not healthy after {timeout}s:"
+                                  f"\n{format_pending_containers(pending)}")
             except click.ClickException as error:
-                # collected rather than raised, so that it cannot hide the apps that failed before
-                problems.append(error.message)
-            else:
-                if execute_hooks:
-                    for app, app_config, instance_domain in upgraded:
-                        logging.info(f"execute commands for {app_config.get('app_domain')}")
-                        execute_cmds(app_config, upgrade=True, instance_domain=instance_domain)
-        if problems:
-            raise click.ClickException("\n".join(problems))
+                # with nothing to read the health off, no app can be told apart from another
+                logging.error(error.message)
+                unhealthy = sorted(config.get('app_domain') for _, config, _ in upgraded)
+            if execute_hooks:
+                hook_failures = run_upgrade_hooks(upgraded, unhealthy)
+        report_upgrade_run(len(upgrade_cmds), failed, unhealthy, hook_failures)
 
 
 @cli.command()
@@ -2776,13 +2849,13 @@ def print_containers(containers: List[Tuple[str, Dict[str, Any]]], verbose: bool
     print(tabulate(rows, 'firstrow', 'rounded_outline'), flush=True)
 
 
-def wait_for_healthy_apps(recipes: Tuple[str], timeout: int, verbose: bool = False, settle: int = 0) -> None:
+def get_unhealthy_apps(recipes: Tuple[str], timeout: int, verbose: bool = False, settle: int = 0) -> List[Tuple[str, Dict[str, Any]]]:
     """
-    Blocks until no service of the selected apps is starting, unknown or unhealthy any more.
+    Waits for the services of the selected apps to settle and reports the ones that never did.
 
     The status is checked after the settle delay and then every PS_WAIT_INTERVAL seconds until the
-    timeout is reached. Having nothing deployed is a failure rather than an early success: waiting
-    for the health of an environment that does not exist would report a broken deployment as green.
+    timeout is reached. Having nothing deployed is a failure rather than an early success: reading
+    the health of an environment that does not exist would report a broken deployment as green.
 
     The delay matters wherever apps are being replaced: such a service keeps reporting its old
     container for a moment, and that one is healthy, it has been running all along. Reading the
@@ -2790,13 +2863,17 @@ def wait_for_healthy_apps(recipes: Tuple[str], timeout: int, verbose: bool = Fal
     built from scratch has nothing to replace and leaves the delay at zero.
 
     Args:
-        recipes (tuple): Recipes to wait for, all of them if empty
+        recipes (tuple): Recipes to read, all of them if empty
         timeout (int): Seconds to wait before giving up
         verbose (bool): Add the chaos, state and image columns to the final table
         settle (int): Seconds to give replaced services to be taken down before the first check
 
+    Returns:
+        list: Tuples of app domain and container for every service that is still not healthy,
+            empty when all of them are
+
     Raises:
-        click.ClickException: If nothing is deployed, or if services are still not healthy when the timeout is reached
+        click.ClickException: If nothing is deployed
     """
     if settle:
         print(f"waiting {settle}s for the replaced services to be taken down", flush=True)
@@ -2811,15 +2888,49 @@ def wait_for_healthy_apps(recipes: Tuple[str], timeout: int, verbose: bool = Fal
         if not pending:
             print_containers(containers, verbose)
             print("All services are healthy")
-            return
+            return []
         if time() >= deadline:
             break
         waiting = ", ".join(f"{domain} {container['service']} ({container['status']})" for domain, container in pending)
         print(f"{len(pending)} service(s) not healthy yet, check again in {PS_WAIT_INTERVAL}s: {waiting}", flush=True)
         sleep(PS_WAIT_INTERVAL)
     print_containers(containers, verbose)
-    report = "\n".join(f"  {domain} {container['service']}: {container['status']}" for domain, container in pending)
-    raise click.ClickException(f"{len(pending)} service(s) still not healthy after {timeout}s:\n{report}")
+    return pending
+
+
+def format_pending_containers(pending: List[Tuple[str, Dict[str, Any]]]) -> str:
+    """
+    Renders the services that never became healthy as one indented line each.
+
+    Args:
+        pending (list): Tuples of app domain and container information
+
+    Returns:
+        str: One line per service, naming its app and its status
+    """
+    return "\n".join(f"  {domain} {container['service']}: {container['status']}"
+                     for domain, container in pending)
+
+
+def wait_for_healthy_apps(recipes: Tuple[str], timeout: int, verbose: bool = False, settle: int = 0) -> None:
+    """
+    Blocks until no service of the selected apps is starting, unknown or unhealthy any more.
+
+    For a caller that has something left to do for the apps that did come back, get_unhealthy_apps()
+    reports them instead of ending the run.
+
+    Args:
+        recipes (tuple): Recipes to wait for, all of them if empty
+        timeout (int): Seconds to wait before giving up
+        verbose (bool): Add the chaos, state and image columns to the final table
+        settle (int): Seconds to give replaced services to be taken down before the first check
+
+    Raises:
+        click.ClickException: If nothing is deployed, or if services are still not healthy when the timeout is reached
+    """
+    if pending := get_unhealthy_apps(recipes, timeout, verbose, settle):
+        raise click.ClickException(f"{len(pending)} service(s) still not healthy after {timeout}s:"
+                                   f"\n{format_pending_containers(pending)}")
 
 
 def get_deployment_traces(recipes: Tuple[str]) -> List[str]:

tests/test_upgrade_hooks.py

@@ -47,9 +47,9 @@ def steps(monkeypatch, versions):
         suffix: "hook:pre:..." would be picked up by every assertion on "hook:".
         """
         kind, key = ("pre-hook", "pre-upgrade-hooks") if kw.get("pre_upgrade") else ("hook", "upgrade-hooks")
-        if not config.get(key):
-            return
-        steps.append(f"{'show:' if dry_run else ''}{kind}:{config['app_domain']}")
+        if config.get(key):
+            steps.append(f"{'show:' if dry_run else ''}{kind}:{config['app_domain']}")
+        return []   # the commands that failed, which execute_cmds reports back
 
     monkeypatch.setattr(alakazam, "execute_cmds", execute_cmds)
 
@@ -73,6 +73,11 @@ def steps(monkeypatch, versions):
     return steps
 
 
+def unhealthy(*domains):
+    """What get_unhealthy_apps() reports for services that never settled."""
+    return [(domain, {"service": "app", "status": "starting"}) for domain in domains]
+
+
 def selected(steps, prefix):
     return [step for step in steps if step.startswith(prefix)]
 
@@ -250,19 +255,12 @@ class TestAFailingApp:
         assert "2 of 2 app(s) failed" in result.exception.message
         assert selected(steps, "ps:") == []
 
-    def test_a_failing_wait_does_not_hide_the_failing_app(self, failing, monkeypatch):
+    def test_an_unhealthy_app_does_not_hide_the_failing_one(self, failing, monkeypatch):
         """One failure covering up another is how a broken app slips through a green pipeline."""
-        monkeypatch.setattr(alakazam, "wait_for_healthy_apps", lambda *a, **k: (_ for _ in ()).throw(
-            click.ClickException("1 service(s) still not healthy after 900s")))
+        monkeypatch.setattr(alakazam, "get_unhealthy_apps", lambda *a, **k: unhealthy("boards.a.org"))
         message = self.invoke(["-e"]).exception.message
-        assert "cloud.a.org" in message
-        assert "still not healthy" in message
-
-    def test_the_hooks_stay_out_when_the_wait_failed(self, failing, monkeypatch):
-        monkeypatch.setattr(alakazam, "wait_for_healthy_apps", lambda *a, **k: (_ for _ in ()).throw(
-            click.ClickException("1 service(s) still not healthy after 900s")))
-        self.invoke(["-e"])
-        assert selected(failing, "hook:") == []
+        assert "failed to upgrade: cloud.a.org" in message
+        assert "did not become healthy: boards.a.org" in message
 
 
 class TestPreUpgradeHooks:
@@ -328,6 +326,7 @@ class TestAFailingPreUpgradeHook:
                     "command 'db update_mongo_version' failed for cloud.a.org: "
                     "FATA no db function in abra.sh")
             steps.append(f"hook:{config['app_domain']}")
+            return []
 
         monkeypatch.setattr(alakazam, "execute_cmds", execute_cmds)
         return steps
@@ -386,3 +385,83 @@ class TestDryRunNamesTheHookKind:
         output = run(["-n", "-e"]).output
         assert "upgrade-hooks for" not in output
         assert "Run 'db update_mongo_version' in cloud.a.org:db" in output
+
+
+class TestAnUnhealthyApp:
+    """
+    An app that does not come back must not cost the apps that did their hooks: a run over twenty
+    apps would otherwise leave nineteen of them half migrated because of one.
+    """
+
+    @pytest.fixture
+    def sick(self, monkeypatch, steps):
+        monkeypatch.setattr(alakazam, "get_unhealthy_apps", lambda *a, **k: unhealthy("cloud.a.org"))
+        return steps
+
+    def invoke(self, args):
+        return CliRunner().invoke(alakazam.upgrade, ["-n"] + args, standalone_mode=False)
+
+    def test_the_healthy_app_still_gets_its_hooks(self, sick):
+        self.invoke(["-e"])
+        assert selected(sick, "hook:") == ["hook:boards.a.org"]
+
+    def test_the_unhealthy_app_does_not(self, sick):
+        """Its hook would reach a container that is not there."""
+        self.invoke(["-e"])
+        assert "hook:cloud.a.org" not in sick
+
+    def test_it_is_reported_and_ends_the_run(self, sick):
+        result = self.invoke(["-e"])
+        assert isinstance(result.exception, click.ClickException)
+        assert "1 of 2 app(s) did not become healthy: cloud.a.org" in result.exception.message
+
+    def test_a_health_check_that_reads_nothing_distrusts_every_app(self, steps, monkeypatch):
+        """Without a status for any of them, none of them can be told apart from a broken one."""
+        monkeypatch.setattr(alakazam, "get_unhealthy_apps", lambda *a, **k: (_ for _ in ()).throw(
+            click.ClickException("no apps are deployed, there is nothing to wait for")))
+        result = self.invoke(["-e"])
+        assert selected(steps, "hook:") == []
+        assert "boards.a.org" in result.exception.message
+        assert "cloud.a.org" in result.exception.message
+
+
+class TestAFailingUpgradeHook:
+    """
+    Reported but not a verdict: hooks still fail for reasons that are not failures, so they are
+    collected until those are sorted out and only then become something the run ends on.
+    """
+
+    @pytest.fixture
+    def broken(self, monkeypatch, steps):
+        def execute_cmds(config, dry_run=False, **kw):
+            if kw.get("pre_upgrade"):
+                return []
+            steps.append(f"hook:{config['app_domain']}")
+            return ["app occ upgrade"] if config["app_domain"] == "cloud.a.org" else []
+
+        monkeypatch.setattr(alakazam, "execute_cmds", execute_cmds)
+        return steps
+
+    def invoke(self, args):
+        return CliRunner().invoke(alakazam.upgrade, ["-n"] + args, standalone_mode=False)
+
+    def test_the_run_still_succeeds(self, broken):
+        result = self.invoke(["-e"])
+        assert result.exit_code == 0, result.exception
+
+    def test_it_is_reported(self, broken, caplog):
+        with caplog.at_level(logging.ERROR):
+            self.invoke(["-e"])
+        assert "1 upgrade hook(s) failed" in caplog.text
+        assert "cloud.a.org 'app occ upgrade'" in caplog.text
+
+    def test_the_other_apps_keep_their_hooks(self, broken):
+        self.invoke(["-e"])
+        assert selected(broken, "hook:") == ["hook:cloud.a.org", "hook:boards.a.org"]
+
+    def test_it_is_reported_next_to_a_failure_that_does_end_the_run(self, broken, monkeypatch, caplog):
+        monkeypatch.setattr(alakazam, "get_unhealthy_apps", lambda *a, **k: unhealthy("boards.a.org"))
+        with caplog.at_level(logging.ERROR):
+            result = self.invoke(["-e"])
+        assert "upgrade hook(s) failed" in caplog.text
+        assert "did not become healthy: boards.a.org" in result.exception.message