tasks: abort the collection chain when a play fails

osism/commands/apply.py

@@ -13,6 +13,22 @@
 from osism.data.enums import Role
 
 
+def _collect_result(result):
+    """Wait for a background task, absorbing an expected play failure.
+
+    A non-zero Ansible rc raises in the worker and is re-raised here. The rc
+    has already been read from the task-output stream, so the exception adds
+    nothing; anything else is unexpected and propagates.
+    """
+    from osism.tasks import AnsibleFailure
+
+    try:
+        result.get()
+    except AnsibleFailure as exc:
+        # Not logger.debug: the sink is pinned to INFO, so that would be silent.
+        logger.info(f"Background task reported a failed play: {exc}")
+
+
 class Run(Command):
     def get_parser(self, prog_name):
         parser = super(Run, self).get_parser(prog_name)
@@ -118,7 +134,7 @@ def handle_loadbalancer_task(self, t, wait, format, timeout):
         # ImportError: sys.meta_path is None, Python is likely shutting down
 
         if not wait:
-            t.parent.get()
+            _collect_result(t.parent)
 
         # process the child tasks
         if format == "log":
@@ -128,7 +144,7 @@ def handle_loadbalancer_task(self, t, wait, format, timeout):
                 )
 
         # As explained above, it is neceesary to wait for all tasks.
-        t.get()
+        _collect_result(t)
 
         return rc
 
@@ -266,6 +282,8 @@ def handle_collection(
             )
             logger.info("Tasks are running in the background")
 
+        return 0
+
     def _prepare_task(
         self,
         arguments,

osism/commands/wait.py

@@ -249,6 +249,16 @@ def take_action(self, parsed_args):
                     if output:
                         print(result.get())
 
+                elif result.state in ["FAILURE", "REVOKED"]:
+                    if format == "log":
+                        logger.error(f"Task {task_id} is in state {result.state}")
+                    elif format == "script":
+                        print(f"{task_id} = {result.state}")
+
+                    # Deliberately no result.get() here even with --output:
+                    # Celery re-raises the task's exception from it.
+                    rc = 1
+
                 elif result.state == "STARTED":
                     if format == "log":
                         logger.info(f"Task {task_id} is in state STARTED")

osism/tasks/__init__.py

@@ -19,6 +19,18 @@
 HOST_PATTERN = re.compile(r"^(ok|changed|failed|skipping|unreachable):\s+\[([^\]]+)\]")
 
 
+class AnsibleFailure(Exception):
+    """Raised when an Ansible run in a worker container exits non-zero.
+
+    Celery marks a task as failed only if it raises, and only a failed task
+    stops the rest of a chain from running.
+
+    The message must carry its own context: with the JSON result serializer
+    Celery keeps only the exception type and its string form. The play output
+    reaches the operator over the Redis output stream, not through here.
+    """
+
+
 class Config:
     broker_connection_retry_on_startup = True
     enable_utc = True
@@ -352,6 +364,14 @@ def run_ansible_in_environment(
             if publish:
                 utils.finish_task_output(request_id, rc=rc)
 
+            # Raise only after the rc has been logged and published, so the
+            # CLI paths that read it from the output stream are unaffected.
+            if rc != 0:
+                raise AnsibleFailure(
+                    f"{worker} play {role} in environment {environment} "
+                    f"failed with rc {rc}"
+                )
+
             return result
         finally:
             if lock:

tests/unit/commands/test_apply.py

@@ -377,6 +377,22 @@ def test_handle_collection_applies_prepared_group(loguru_logs):
     assert "Tasks are running in the background" in messages
 
 
+def test_handle_collection_returns_zero_exit_code(loguru_logs):
+    """``handle_collection`` has to return an exit code, not ``None``.
+
+    ``take_action`` tests the result with ``if rc != 0``, and ``None != 0`` is
+    True, so returning ``None`` made every collection look like a failure and
+    skip the remaining ``//`` segments.
+    """
+    cmd = make_command(apply.Run)
+    cmd._handle_collection = MagicMock(return_value=MagicMock())
+
+    with patch.dict(enums.MAP_ROLE2ROLE, {"testcollection": [Role("a")]}):
+        rc = cmd.handle_collection(**_public_collection_kwargs())
+
+    assert rc == 0
+
+
 def test_handle_collection_show_tree_does_not_apply(loguru_logs):
     cmd = make_command(apply.Run)
     prepared = MagicMock()
@@ -517,6 +533,29 @@ def test_handle_loadbalancer_task_group_failure_propagates(mocker):
     handle_task.assert_called_once_with(t.parent, True, "log", 300)
 
 
+def test_handle_loadbalancer_task_absorbs_ansible_failure(mocker):
+    """A failed play must not surface as a traceback here.
+
+    Now that the task raises on a non-zero Ansible rc, ``t.get()`` re-raises
+    it. The rc has already been read from the task-output stream by
+    ``handle_task``, so the exception carries no new information and must be
+    absorbed -- unlike the unexpected exceptions pinned above, which still
+    propagate.
+    """
+    from osism.tasks import AnsibleFailure
+
+    handle_task = mocker.patch("osism.tasks.handle_task", return_value=4)
+    cmd = make_command(apply.Run)
+    t = MagicMock()
+    t.children = [MagicMock(task_id="child-1")]
+    t.get.side_effect = AnsibleFailure("play failed")
+
+    rc = cmd.handle_loadbalancer_task(t, True, "log", 300)
+
+    assert rc == 4
+    handle_task.assert_called_once_with(t.parent, True, "log", 300)
+
+
 # take_action
 
 
@@ -655,12 +694,6 @@ def test_take_action_routes_collection_to_handle_collection(take_action_mocks):
     assert cmd.handle_collection.call_args.args[4] == "testcollection"
 
 
-@pytest.mark.xfail(
-    strict=True,
-    reason="handle_collection returns None instead of an exit code, so the "
-    "'//' loop treats a successful collection as failed, silently skips the "
-    "remaining segments and take_action returns None (exit 0)",
-)
 def test_take_action_collection_chain_continues_after_success(take_action_mocks):
     """A successful collection segment must not swallow the following ``//``
     segments: ``osism apply testcollection//other`` has to schedule the

tests/unit/commands/test_wait.py

@@ -494,3 +494,75 @@ def test_peek_failure_is_reported_at_a_visible_level(loguru_logs):
     notices = [r for r in loguru_logs if "stall reporting" in r["message"].lower()]
     assert len(notices) == 1
     assert notices[0]["level"] in ("WARNING", "ERROR")
+
+
+# terminal failure states
+
+
+def test_failed_task_sets_nonzero_exit_code(loguru_logs):
+    """A FAILURE task must set a non-zero exit code.
+
+    Before the fix the loop branched on PENDING/SUCCESS/STARTED only, so a
+    FAILURE task fell through every branch, was dropped from the queue without
+    being re-queued, and ``rc`` stayed 0 -- which is why an aborted collection
+    chain still let ``deploy-in-a-nutshell.sh`` exit 0 under ``set -e``.
+    """
+    mocks = _run_states(
+        ["taskid1"],
+        results=[_make_result("FAILURE")],
+    )
+
+    assert mocks.rc == 1
+    assert mocks.async_result.call_count == 1
+    mocks.sleep.assert_not_called()
+    assert "Task taskid1 is in state FAILURE" in [
+        record["message"] for record in loguru_logs
+    ]
+
+
+def test_revoked_task_sets_nonzero_exit_code(loguru_logs):
+    mocks = _run_states(
+        ["taskid1"],
+        results=[_make_result("REVOKED")],
+    )
+
+    assert mocks.rc == 1
+    assert "Task taskid1 is in state REVOKED" in [
+        record["message"] for record in loguru_logs
+    ]
+
+
+def test_failure_is_not_reset_by_a_later_successful_task():
+    """``rc`` has to survive the rest of the queue.
+
+    IDs are sorted and popped from the end, so ``taskid2`` is inspected first;
+    the SUCCESS branch that follows must not clear the recorded failure.
+    """
+    mocks = _run_states(
+        ["taskid1", "taskid2"],
+        results=[_make_result("FAILURE"), _make_result("SUCCESS")],
+    )
+
+    assert mocks.rc == 1
+
+
+def test_failed_task_with_output_does_not_fetch_the_result():
+    """``--output`` must not call ``result.get()`` on a failed task: Celery
+    re-raises the task's exception there, which would replace the exit code
+    with a traceback."""
+    result = _make_result("FAILURE")
+    mocks = _run_states(["taskid1", "--output"], results=[result])
+
+    assert mocks.rc == 1
+    result.get.assert_not_called()
+
+
+def test_script_format_prints_failure_state(capsys, loguru_logs):
+    mocks = _run_states(
+        ["taskid1", "--format", "script"],
+        results=[_make_result("FAILURE")],
+    )
+
+    assert mocks.rc == 1
+    assert capsys.readouterr().out == "taskid1 = FAILURE\n"
+    assert not any("taskid1" in record["message"] for record in loguru_logs)

tests/unit/tasks/test_init.py

@@ -528,13 +528,51 @@ def test_run_ansible_logs_start_then_success_with_sorted_hosts(runner_mocks):
 
 
 def test_run_ansible_nonzero_rc_logs_failure(runner_mocks):
+    """A non-zero rc is still logged and still published to the output stream.
+
+    The raise added for chain abortion must happen *after* both, so the
+    non-collection CLI path -- which reads the rc back out of the Redis stream
+    rather than out of the Celery result -- keeps working unchanged.
+    """
     runner_mocks.popen.return_value = make_process(["ok: [node-1]\n"], rc=1)
-    run_ansible()
+    with pytest.raises(tasks.AnsibleFailure):
+        run_ansible()
     calls = runner_mocks.log_play.call_args_list
     assert calls[1].kwargs["result"] == "failure"
     runner_mocks.finish.assert_called_once_with("req-1", rc=1)
 
 
+def test_run_ansible_nonzero_rc_raises_with_context(runner_mocks):
+    """The exception message has to identify the play, since it is all the
+    Celery result backend keeps -- the output itself is not serialized."""
+    runner_mocks.popen.return_value = make_process(["ok: [node-1]\n"], rc=2)
+    with pytest.raises(tasks.AnsibleFailure) as excinfo:
+        run_ansible(worker="kolla-ansible", environment="kolla", role="keystone")
+    message = str(excinfo.value)
+    assert "kolla-ansible" in message
+    assert "kolla" in message
+    assert "keystone" in message
+    assert "2" in message
+
+
+def test_run_ansible_nonzero_rc_releases_lock_and_cleans_ssh_dir(runner_mocks):
+    """Raising must not leak the redlock or the per-task ControlPath dir; both
+    are released in ``finally`` blocks the raise passes through."""
+    lock = runner_mocks.create_redlock.return_value
+    runner_mocks.popen.return_value = make_process(["ok: [node-1]\n"], rc=1)
+
+    with pytest.raises(tasks.AnsibleFailure):
+        run_ansible(locking=True)
+
+    lock.release.assert_called_once_with()
+    runner_mocks.rmtree.assert_called_once()
+
+
+def test_run_ansible_zero_rc_does_not_raise(runner_mocks):
+    runner_mocks.popen.return_value = make_process(["ok: [node-1]\n"], rc=0)
+    assert run_ansible() == "ok: [node-1]\n"
+
+
 def test_run_ansible_duplicate_hosts_deduplicated(runner_mocks):
     runner_mocks.popen.return_value = make_process(
         ["ok: [node-1]\n", "changed: [node-1]\n"], rc=0