mirror of
https://github.com/kevinveenbirkenbach/computer-playbook.git
synced 2026-11-06 19:01:54 +00:00
docker stack deploy --detach=false converges on a running replica. web-svc-cdn's build container and every migration job end Shutdown/Complete by design, so the CLI waited for a state those stacks cannot reach: nine jobs of run 33698844864 burned the runner's 20400s budget inside this one handler, six of them on web-svc-cdn. The gate that follows already knows better, is_completed_oneshot accepts exactly that task shape.
The timeout keyword could not bound it either. The stack host is reached over ansible_connection: docker, whose plugin runs the child inside a Popen context manager, and __exit__ waits the child out before the timeout exception escapes; a probe measured 90s of wall clock against a 6s timeout. The bound now sits in the shell, where it works.
Handing the wait back to the gate would reopen the race 87e4313e11 closed, so the deploy stamps its start and names the services it reported touching, and the gate treats their earlier completed update as still pending. An inspect format the daemon rejects falls back to the old one, which only disables that check.
Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>
413 lines
16 KiB
Python
413 lines
16 KiB
Python
"""Behaviour of the swarm convergence gate.
|
|
|
|
``stack_ready.sh`` decides whether a swarm deploy is done. It is driven by an
|
|
Ansible ``until`` loop that keeps polling on rc 1 and gives up at once on rc 2,
|
|
so both its verdict and how much it prints on a failing poll matter. Exercised
|
|
here against a stub docker: a fully replicated stack passes, a short one keeps
|
|
the caller waiting, a completed one-shot counts as done, and every task row
|
|
reaches the caller.
|
|
|
|
The two terminal verdicts are split by the task's current state, because that is
|
|
what says whether docker ever ran the container. A task rejected or left
|
|
unschedulable never started, so docker has already judged the spec unrunnable
|
|
and the verdict needs no clock. A task that failed did run, and a crash loop
|
|
waiting out a dependency is indistinguishable from one that never converges, so
|
|
only the grace-gated strike counter may end it - never on the newest row alone,
|
|
and never on errors left below a finished attempt. That counter is armed off the
|
|
service's own ``UpdatedAt``, so an unreadable epoch has to keep the caller
|
|
waiting rather than arm it.
|
|
|
|
A service whose ``UpdateStatus`` latched or rolled back is terminal on its own,
|
|
without any task row: swarm will not leave that state until the next stack
|
|
deploy, and a revert leaves the replica count full for the previous spec. A
|
|
service still ``updating`` keeps the caller waiting instead, and so does a
|
|
service whose desired replicas are only met by old-spec tasks that have not been
|
|
replaced yet - docker's own replica column counts those as running, so the gate
|
|
counts the tasks carrying desired-state=running rather than reading that column.
|
|
"""
|
|
|
|
from __future__ import annotations
|
|
|
|
import os
|
|
import subprocess
|
|
import tempfile
|
|
import time
|
|
import unittest
|
|
from pathlib import Path
|
|
|
|
from utils.cache.files import PROJECT_ROOT
|
|
|
|
GATE = (
|
|
PROJECT_ROOT
|
|
/ "roles"
|
|
/ "sys-svc-compose"
|
|
/ "files"
|
|
/ "shell"
|
|
/ "swarm"
|
|
/ "stack_ready.sh"
|
|
)
|
|
STUB = """#!/usr/bin/env bash
|
|
case "$1 $2" in
|
|
"stack services") printf '%s' "${STACK_SERVICES}" ;;
|
|
"service inspect")
|
|
case "$4" in
|
|
*UpdatedAt*) printf '%s' "${SERVICE_UPDATED_AT}" ;;
|
|
*StartedAt*)
|
|
[ -n "${INSPECT_STARTEDAT_FAILS}" ] && exit 1
|
|
printf '%s' "${SERVICE_INSPECT}"
|
|
;;
|
|
*) printf '%s' "${SERVICE_INSPECT_PLAIN:-${SERVICE_INSPECT}}" ;;
|
|
esac
|
|
;;
|
|
"service ps")
|
|
case "$*" in
|
|
*'desired-state=running'*)
|
|
printf '%s' "${SERVICE_RUNNING}" | awk -F'|' -v s="$3" '$1 == s { print $2 }'
|
|
;;
|
|
*'{{.Name}}|{{.CurrentState}}|{{.Error}}'*) printf '%s' "${SERVICE_ERRORS}" ;;
|
|
*) printf '%s' "${SERVICE_PS}" ;;
|
|
esac
|
|
;;
|
|
esac
|
|
exit 0
|
|
"""
|
|
WEB_THREE_RUNNING = (
|
|
"demo_web|Running 2 minutes ago\n"
|
|
"demo_web|Running 2 minutes ago\n"
|
|
"demo_web|Running 2 minutes ago\n"
|
|
)
|
|
|
|
|
|
class TestStackReady(unittest.TestCase):
|
|
def _run(
|
|
self,
|
|
services: str,
|
|
service_ps: str = "",
|
|
service_errors: str = "",
|
|
service_inspect: str = "",
|
|
service_running: str = "",
|
|
churning: int = 0,
|
|
updated_at: str | None = None,
|
|
deploy_since: str = "",
|
|
deployed_services: str = "",
|
|
inspect_startedat_fails: bool = False,
|
|
service_inspect_plain: str = "",
|
|
) -> subprocess.CompletedProcess:
|
|
"""Poll the gate once, ``churning`` seconds into a non-converged deploy.
|
|
|
|
Args:
|
|
services: ``docker stack services`` table the stub returns.
|
|
service_ps: verbose ``docker service ps`` table for the report.
|
|
service_errors: ``name|current state|error`` rows, newest first.
|
|
service_inspect: ``name update-state`` rows for the latched check.
|
|
service_running: ``service|current state`` rows carrying
|
|
desired-state=running, one per task of the current spec.
|
|
churning: seconds since the deploy bumped the service ``UpdatedAt``.
|
|
updated_at: raw ``UpdatedAt`` epoch, overriding ``churning``.
|
|
deploy_since: epoch seconds the deploy stamped before it ran.
|
|
deployed_services: space-separated services the deploy reported
|
|
creating or updating.
|
|
inspect_startedat_fails: reject the StartedAt format, as an older
|
|
docker would.
|
|
service_inspect_plain: rows the fallback format returns.
|
|
"""
|
|
if updated_at is None:
|
|
updated_at = str(int(time.time()) - churning)
|
|
with tempfile.TemporaryDirectory() as tmp:
|
|
stub_bin = Path(tmp) / "bin"
|
|
stub_bin.mkdir()
|
|
docker = stub_bin / "docker"
|
|
docker.write_text(STUB)
|
|
docker.chmod(0o755)
|
|
timeout = stub_bin / "timeout"
|
|
timeout.write_text('#!/usr/bin/env bash\nshift\nexec "$@"\n')
|
|
timeout.chmod(0o755)
|
|
|
|
env = dict(os.environ)
|
|
env.update(
|
|
STACK="demo",
|
|
FATAL_GRACE="180",
|
|
STACK_SERVICES=services,
|
|
SERVICE_PS=service_ps,
|
|
SERVICE_ERRORS=service_errors,
|
|
SERVICE_INSPECT=service_inspect,
|
|
SERVICE_RUNNING=service_running,
|
|
SERVICE_UPDATED_AT=updated_at,
|
|
DEPLOY_SINCE=deploy_since,
|
|
DEPLOYED_SERVICES=deployed_services,
|
|
INSPECT_STARTEDAT_FAILS="1" if inspect_startedat_fails else "",
|
|
SERVICE_INSPECT_PLAIN=service_inspect_plain,
|
|
PATH=f"{stub_bin}:{env['PATH']}",
|
|
BASH_ENV="",
|
|
)
|
|
return subprocess.run(
|
|
["bash", str(GATE)],
|
|
env=env,
|
|
capture_output=True,
|
|
text=True,
|
|
check=False,
|
|
)
|
|
|
|
def test_a_service_with_no_update_in_flight_converges(self) -> None:
|
|
proc = self._run(
|
|
"demo_web 3/3\n",
|
|
service_inspect="demo_web none\n",
|
|
service_running=WEB_THREE_RUNNING,
|
|
)
|
|
self.assertEqual(proc.returncode, 0)
|
|
|
|
def test_an_update_in_flight_keeps_the_caller_waiting(self) -> None:
|
|
proc = self._run(
|
|
"demo_web 3/3\n",
|
|
service_ps="demo_web.1 desired=Running current=Starting error=\n",
|
|
service_inspect="demo_web updating\n",
|
|
service_running=WEB_THREE_RUNNING,
|
|
)
|
|
self.assertEqual(proc.returncode, 1)
|
|
self.assertIn("demo_web(updating)", proc.stderr)
|
|
self.assertIn("rolling update still in flight", proc.stderr)
|
|
|
|
def test_the_previous_rounds_completed_update_does_not_count_as_converged(
|
|
self,
|
|
) -> None:
|
|
proc = self._run(
|
|
"demo_web 3/3\n",
|
|
service_inspect="demo_web completed 1788397200\n",
|
|
service_running=WEB_THREE_RUNNING,
|
|
deploy_since="1788398643",
|
|
deployed_services="demo_web",
|
|
)
|
|
self.assertEqual(proc.returncode, 1)
|
|
self.assertIn("demo_web(pending)", proc.stderr)
|
|
|
|
def test_a_service_the_deploy_left_alone_converges_on_its_old_update(
|
|
self,
|
|
) -> None:
|
|
proc = self._run(
|
|
"demo_web 3/3\n",
|
|
service_inspect="demo_web completed 1788397200\n",
|
|
service_running=WEB_THREE_RUNNING,
|
|
deploy_since="1788398643",
|
|
deployed_services="demo_other",
|
|
)
|
|
self.assertEqual(proc.returncode, 0)
|
|
|
|
def test_an_update_registered_after_the_deploy_converges(self) -> None:
|
|
proc = self._run(
|
|
"demo_web 3/3\n",
|
|
service_inspect="demo_web completed 1788398649\n",
|
|
service_running=WEB_THREE_RUNNING,
|
|
deploy_since="1788398643",
|
|
deployed_services="demo_web",
|
|
)
|
|
self.assertEqual(proc.returncode, 0)
|
|
|
|
def test_a_stamp_that_is_not_epoch_seconds_disables_the_check(self) -> None:
|
|
proc = self._run(
|
|
"demo_web 3/3\n",
|
|
service_inspect="demo_web completed 2026-09-03 01:00:00 +0000 UTC\n",
|
|
service_running=WEB_THREE_RUNNING,
|
|
deploy_since="2026-09-03T01:24:03Z",
|
|
deployed_services="demo_web",
|
|
)
|
|
self.assertEqual(proc.returncode, 0)
|
|
|
|
def test_a_docker_that_rejects_the_stamp_format_falls_back_instead_of_stalling(
|
|
self,
|
|
) -> None:
|
|
proc = self._run(
|
|
"demo_web 3/3\n",
|
|
service_running=WEB_THREE_RUNNING,
|
|
deploy_since="1788398643",
|
|
deployed_services="demo_web",
|
|
inspect_startedat_fails=True,
|
|
service_inspect_plain="demo_web completed -\n",
|
|
)
|
|
self.assertEqual(proc.returncode, 0)
|
|
|
|
def test_a_service_without_a_recorded_update_start_is_left_alone(self) -> None:
|
|
proc = self._run(
|
|
"demo_web 3/3\n",
|
|
service_inspect="demo_web completed -\n",
|
|
service_running=WEB_THREE_RUNNING,
|
|
deploy_since="1788398643",
|
|
deployed_services="demo_web",
|
|
)
|
|
self.assertEqual(proc.returncode, 0)
|
|
|
|
def test_without_a_deploy_stamp_the_gate_keeps_its_old_behaviour(self) -> None:
|
|
proc = self._run(
|
|
"demo_web 3/3\n",
|
|
service_inspect="demo_web completed 1788397200\n",
|
|
service_running=WEB_THREE_RUNNING,
|
|
)
|
|
self.assertEqual(proc.returncode, 0)
|
|
|
|
def test_old_spec_tasks_left_running_do_not_fill_the_replica_count(self) -> None:
|
|
"""Docker's replica column counts every Running task, draining old-spec
|
|
ones included, so a stack mid-rollout reads as full."""
|
|
proc = self._run(
|
|
"demo_web 3/3\n",
|
|
service_ps="demo_web.1 desired=Running current=Preparing error=\n",
|
|
service_inspect="demo_web completed\n",
|
|
service_running=(
|
|
"demo_web|Running 2 minutes ago\ndemo_web|Running 2 minutes ago\n"
|
|
),
|
|
)
|
|
self.assertEqual(proc.returncode, 1)
|
|
self.assertIn("not converged", proc.stderr)
|
|
self.assertIn("demo_web", proc.stderr)
|
|
|
|
def test_a_latched_update_gives_up_instead_of_polling(self) -> None:
|
|
for latched in ("paused", "rollback_paused"):
|
|
with self.subTest(state=latched):
|
|
proc = self._run(
|
|
"demo_web 3/3\n",
|
|
service_ps="demo_web.1 desired=Shutdown current=Failed error=oom\n",
|
|
service_inspect=f"demo_web {latched}\n",
|
|
)
|
|
self.assertEqual(proc.returncode, 2)
|
|
self.assertIn(f"demo_web({latched})", proc.stderr)
|
|
self.assertIn("without another stack deploy", proc.stderr)
|
|
|
|
def test_a_rolled_back_update_fails_even_though_replicas_are_full(self) -> None:
|
|
"""A revert leaves N/N of the PREVIOUS spec, so the replica check alone
|
|
would report this stack as converged."""
|
|
for reverted in ("rollback_started", "rollback_completed"):
|
|
with self.subTest(state=reverted):
|
|
proc = self._run(
|
|
"demo_web 3/3\n", service_inspect=f"demo_web {reverted}\n"
|
|
)
|
|
self.assertEqual(proc.returncode, 2)
|
|
self.assertIn(f"demo_web({reverted})", proc.stderr)
|
|
|
|
def test_a_fully_replicated_stack_converges(self) -> None:
|
|
proc = self._run(
|
|
"demo_web 3/3\ndemo_db 1/1\n",
|
|
service_running=WEB_THREE_RUNNING + "demo_db|Running 4 minutes ago\n",
|
|
)
|
|
self.assertEqual(proc.returncode, 0)
|
|
|
|
def test_a_short_service_does_not_converge(self) -> None:
|
|
proc = self._run("demo_web 2/3\n")
|
|
self.assertEqual(proc.returncode, 1)
|
|
self.assertIn("not converged", proc.stderr)
|
|
self.assertIn("demo_web", proc.stderr)
|
|
|
|
def test_a_completed_oneshot_counts_as_converged(self) -> None:
|
|
proc = self._run(
|
|
"demo_init 0/1\n",
|
|
"demo_init.1|Shutdown|Complete 3 minutes ago\n",
|
|
)
|
|
self.assertEqual(proc.returncode, 0)
|
|
|
|
def test_a_rejected_task_is_terminal_without_any_grace(self) -> None:
|
|
proc = self._run(
|
|
"demo_reg 0/1\n",
|
|
"demo_reg.1 desired=Ready current=Rejected error=No such image: reg/nope\n",
|
|
"demo_reg.1|Rejected 3 seconds ago|No such image: reg/nope\n",
|
|
)
|
|
self.assertEqual(proc.returncode, 2)
|
|
self.assertIn("No such image", proc.stderr)
|
|
self.assertIn("stuck: demo_reg", proc.stderr)
|
|
|
|
def test_an_unschedulable_task_is_terminal_without_any_grace(self) -> None:
|
|
proc = self._run(
|
|
"demo_place 0/1\n",
|
|
"demo_place.1 desired=Running current=Pending error=no suitable node\n",
|
|
"demo_place.1|Pending 28 seconds ago|no suitable node\n",
|
|
)
|
|
self.assertEqual(proc.returncode, 2)
|
|
self.assertIn("stuck: demo_place", proc.stderr)
|
|
|
|
def test_a_newest_failed_attempt_alone_is_never_terminal(self) -> None:
|
|
"""A container that ran and died may still be waiting out a dependency."""
|
|
proc = self._run(
|
|
"demo_boot 0/1\n",
|
|
"demo_boot.1 desired=Shutdown current=Failed error=task: non-zero exit (1)\n",
|
|
"demo_boot.1|Failed 1 second ago|task: non-zero exit (1)\n",
|
|
)
|
|
self.assertEqual(proc.returncode, 1)
|
|
self.assertNotIn("stuck:", proc.stderr)
|
|
|
|
def test_error_free_task_rows_are_echoed_and_keep_the_caller_waiting(self) -> None:
|
|
proc = self._run(
|
|
"demo_slow 0/1\n",
|
|
"demo_slow.1 desired=Running current=Preparing error=\n",
|
|
"demo_slow.1|Preparing 2 seconds ago|\n",
|
|
)
|
|
self.assertEqual(proc.returncode, 1)
|
|
self.assertIn("demo_slow.1", proc.stderr)
|
|
self.assertIn("current=Preparing", proc.stderr)
|
|
|
|
def test_a_fresh_attempt_after_two_failures_still_waits(self) -> None:
|
|
proc = self._run(
|
|
"demo_boot 0/1\n",
|
|
"demo_boot.1 desired=Running current=Starting error=\n",
|
|
"demo_boot.1|Ready 1 second ago|\n"
|
|
"demo_boot.1|Failed 2 seconds ago|task: non-zero exit (1)\n"
|
|
"demo_boot.1|Failed 8 seconds ago|task: non-zero exit (1)\n",
|
|
churning=600,
|
|
)
|
|
self.assertEqual(proc.returncode, 1)
|
|
|
|
def test_a_slot_that_burned_three_attempts_is_terminal(self) -> None:
|
|
proc = self._run(
|
|
"demo_flap 0/1\n",
|
|
"demo_flap.1 desired=Running current=Starting error=\n",
|
|
"demo_flap.1|Ready 1 second ago|\n"
|
|
"demo_flap.1|Failed 2 seconds ago|task: non-zero exit (1)\n"
|
|
"demo_flap.1|Failed 8 seconds ago|task: non-zero exit (1)\n"
|
|
"demo_flap.1|Failed 14 seconds ago|task: non-zero exit (1)\n",
|
|
churning=600,
|
|
)
|
|
self.assertEqual(proc.returncode, 2)
|
|
self.assertIn("stuck: demo_flap", proc.stderr)
|
|
|
|
def test_three_attempts_inside_the_grace_window_still_wait(self) -> None:
|
|
proc = self._run(
|
|
"demo_flap 0/1\n",
|
|
"demo_flap.1 desired=Running current=Starting error=\n",
|
|
"demo_flap.1|Ready 1 second ago|\n"
|
|
"demo_flap.1|Failed 2 seconds ago|task: non-zero exit (1)\n"
|
|
"demo_flap.1|Failed 8 seconds ago|task: non-zero exit (1)\n"
|
|
"demo_flap.1|Failed 14 seconds ago|task: non-zero exit (1)\n",
|
|
)
|
|
self.assertEqual(proc.returncode, 1)
|
|
|
|
def test_errors_below_a_finished_attempt_do_not_carry_over(self) -> None:
|
|
proc = self._run(
|
|
"demo_again 0/1\n",
|
|
"demo_again.1 desired=Running current=Pending error=\n",
|
|
"demo_again.1|Pending 1 second ago|\n"
|
|
"demo_again.1|Shutdown 4 seconds ago|\n"
|
|
"demo_again.1|Failed 9 seconds ago|task: non-zero exit (1)\n"
|
|
"demo_again.1|Failed 15 seconds ago|task: non-zero exit (1)\n"
|
|
"demo_again.1|Failed 21 seconds ago|task: non-zero exit (1)\n",
|
|
churning=600,
|
|
)
|
|
self.assertEqual(proc.returncode, 1)
|
|
|
|
def test_an_unreadable_deploy_epoch_keeps_the_caller_waiting(self) -> None:
|
|
proc = self._run(
|
|
"demo_flap 0/1\n",
|
|
"demo_flap.1 desired=Running current=Starting error=\n",
|
|
"demo_flap.1|Ready 1 second ago|\n"
|
|
"demo_flap.1|Failed 2 seconds ago|task: non-zero exit (1)\n"
|
|
"demo_flap.1|Failed 8 seconds ago|task: non-zero exit (1)\n"
|
|
"demo_flap.1|Failed 14 seconds ago|task: non-zero exit (1)\n",
|
|
updated_at="<no value>",
|
|
)
|
|
self.assertEqual(proc.returncode, 1)
|
|
|
|
def test_a_missing_task_state_dump_is_not_echoed_as_a_blank_line(self) -> None:
|
|
proc = self._run(
|
|
"demo_slow 0/1\n",
|
|
"demo_slow.1 desired=Running current=Preparing error=\n",
|
|
)
|
|
self.assertNotIn("\n \n", proc.stderr)
|
|
|
|
|
|
if __name__ == "__main__":
|
|
unittest.main()
|