From a80c6a76b54c00e02902eb87b39ba853c10a1e26 Mon Sep 17 00:00:00 2001 From: Brian Krabach Date: Sun, 17 May 2026 18:28:54 -0700 Subject: [PATCH] fix(cli): verify service is actually active after start, daemon-reload first for stale units MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit During the v0.6.5→v0.6.6 rollout on spark-1 (systemd Linux) the upgrade flow printed 'Restarting systemd service...' and 'Service started' but the unit was actually inactive (dead) for 14 minutes afterward. The PWA was dark and no alert fired because the CLI reported success. Root cause: we fired daemon-reload + start but never verified the result. If the unit was left in a 'failed' state (e.g. stale unit-file mismatch after the previous ExecStart was regenerated mid-upgrade), systemd silently ignored the start. Fix: * Add _probe_service_port(port) — lightweight HTTP probe to localhost:port/login that returns True on any HTTP response. * Add _verify_service_started(timeout_s=10) — polls 'systemctl --user is-active' once (synchronous path) or polls the port via HTTP (async launchctl path) and returns True/False. * In upgrade() finally block (systemd path): call daemon-reload BEFORE start (already present but now documented), then call _verify_service_started(). If not active, do reset-failed + retry start once. If still not active, print a clear error and set _service_restart_failed = True. * Propagate _service_restart_failed as sys.exit(1) after the try/finally, so callers and scripts can detect that the service is not running. * Augment doctor() systemd check: probe is-active and downgrade to a warn '!' marker when the unit file exists but the service is not active. * Augment doctor() launchd check: probe the HTTP port after confirming the agent is registered; report '! launchd agent registered but not serving on port N' when the port is not responding (catches the silent-failure mode from Fix 2 as well). Tests added (test_cli.py, under 'v0.6.7 fixes'): - _verify_service_started returns True when is-active exits 0 - _verify_service_started returns False when is-active exits 3 (inactive) - upgrade() exits 1 when service fails to restart after install - upgrade() calls daemon-reload before start (call-order assertion) - doctor() reports 'registered but not serving' when launchd agent is up but port is not bound --- muxplex/cli.py | 148 +++++++++++++++++++++++++++++++-- muxplex/tests/test_cli.py | 171 ++++++++++++++++++++++++++++++++++++++ 2 files changed, 311 insertions(+), 8 deletions(-) diff --git a/muxplex/cli.py b/muxplex/cli.py index 9a4b66c..2900e5a 100644 --- a/muxplex/cli.py +++ b/muxplex/cli.py @@ -31,6 +31,77 @@ def _have_launchctl() -> bool: return shutil.which("launchctl") is not None +def _probe_service_port(port: int) -> bool: + """Return True if a muxplex server is responding on localhost:port. + + Tries HTTPS first (self-signed cert tolerated), then HTTP. Any HTTP + response code (including 4xx/5xx) confirms the server is listening. + A connection error, timeout, or SSL failure means the server is not up. + """ + import ssl + import urllib.error + import urllib.request + + for scheme in ("https", "http"): + try: + url = f"{scheme}://localhost:{port}/login" + if scheme == "https": + ctx = ssl.create_default_context() + ctx.check_hostname = False + ctx.verify_mode = ssl.CERT_NONE + with urllib.request.urlopen(url, timeout=5, context=ctx) as _resp: + return True + else: + with urllib.request.urlopen(url, timeout=5) as _resp: + return True + except urllib.error.HTTPError: + # Server returned an HTTP error — it IS running + return True + except Exception: + pass # Connection refused, timeout, SSL issue — try next scheme + return False + + +def _verify_service_started(timeout_s: int = 10) -> bool: + """Verify the muxplex service is actually serving after a start command. + + For systemctl: calls ``systemctl --user is-active muxplex`` once and + returns ``True`` only when the unit is ``active`` (exit code 0). + ``systemctl start`` is synchronous so a single check is sufficient. + + For launchctl: polls ``_probe_service_port()`` until a successful HTTP + response is received or ``timeout_s`` seconds have elapsed. launchd + starts processes asynchronously, so polling is necessary. + + Returns ``False`` if the service is not active / not responding. + """ + import time + + if _have_systemctl(): + result = subprocess.run( + ["systemctl", "--user", "is-active", "muxplex"], + capture_output=True, + text=True, + ) + return result.returncode == 0 + + if _have_launchctl(): + from muxplex.settings import load_settings # noqa: PLC0415 + + cfg = load_settings() + port = cfg.get("port", 8088) + deadline = time.monotonic() + timeout_s + while True: + if _probe_service_port(port): + return True + remaining = deadline - time.monotonic() + if remaining <= 0: + return False + time.sleep(min(1.0, remaining)) + + return False + + def _find_uv() -> str | None: """Locate the ``uv`` binary, checking PATH first then well-known install locations. @@ -503,7 +574,18 @@ def doctor() -> None: text=True, ) if result.returncode == 0: - print(f" {ok_mark} Service: launchd agent running") + # Agent is registered — verify it is actually serving + from muxplex.settings import load_settings # noqa: PLC0415 + + _cfg = load_settings() + _port = _cfg.get("port", 8088) + if _probe_service_port(_port): + print(f" {ok_mark} Service: launchd agent running") + else: + print( + f" {warn_mark} Service: launchd agent registered but" + f" not serving on port {_port}" + ) else: print( f" {warn_mark} Service: launchd agent installed but not running ({plist})" @@ -524,9 +606,21 @@ def doctor() -> None: Path.home() / ".config" / "systemd" / "user" / "muxplex.service" ) if systemd_user.exists(): - print( - f" {ok_mark} Service: systemd user unit installed ({systemd_user})" + _active = subprocess.run( + ["systemctl", "--user", "is-active", "muxplex"], + capture_output=True, + text=True, ) + if _active.returncode == 0: + print( + f" {ok_mark} Service: systemd user unit installed ({systemd_user})" + ) + else: + _state = _active.stdout.strip() or "unknown" + print( + f" {warn_mark} Service: systemd user unit installed but" + f" not active — state: {_state} ({systemd_user})" + ) elif _system_service_path.exists(): print( f" {ok_mark} Service: systemd system unit installed ({_system_service_path})" @@ -644,6 +738,7 @@ def upgrade(*, force: bool = False) -> None: # 2+4. Install (try) with guaranteed service restart in finally. # Bug 1+2b: try/finally ensures the start step always runs — success OR failure. _install_failed = False + _service_restart_failed = False print(" Installing latest version...") try: # Bug 3: dispatch — uv-tool-managed gets --reinstall; plain uv/pip otherwise @@ -705,14 +800,21 @@ def upgrade(*, force: bool = False) -> None: capture_output=True, text=True, ) - if result.returncode == 0: - print(" Service started") - else: + if result.returncode != 0: # Fallback to legacy load for older macOS subprocess.run( ["launchctl", "load", str(plist)], capture_output=True ) - print(" Service started (legacy)") + # Verify the agent is actually serving (not just registered) + if _verify_service_started(): + print(" Service started") + else: + print( + " ERROR: launchd agent registered but the service is" + " not responding after upgrade.\n" + " Check /tmp/muxplex.err for details." + ) + _service_restart_failed = True else: print(" Service file not found — run: muxplex service install") elif _have_systemctl(): @@ -723,13 +825,35 @@ def upgrade(*, force: bool = False) -> None: ) if result.returncode == 0: print(" Restarting systemd service...") + # daemon-reload FIRST: picks up any regenerated unit file so + # the start command sees the correct ExecStart (spark-1 fix). subprocess.run( ["systemctl", "--user", "daemon-reload"], capture_output=True ) subprocess.run( ["systemctl", "--user", "start", "muxplex"], capture_output=True ) - print(" Service started") + if not _verify_service_started(): + # Unit may have landed in 'failed' state (e.g. port race + # on first start). Reset the failure counter and retry once. + subprocess.run( + ["systemctl", "--user", "reset-failed", "muxplex"], + capture_output=True, + ) + subprocess.run( + ["systemctl", "--user", "start", "muxplex"], + capture_output=True, + ) + if _verify_service_started(): + print(" Service started") + else: + print( + " ERROR: muxplex service is not active after upgrade.\n" + " Run: systemctl --user status muxplex" + ) + _service_restart_failed = True + else: + print(" Service started") else: print(" Service not enabled — run: muxplex service install") else: @@ -759,6 +883,14 @@ def upgrade(*, force: bool = False) -> None: ) sys.exit(1) + if _service_restart_failed: + print( + "\n ERROR: upgrade installed successfully but the service failed to restart.\n" + " The new version is installed but the service is NOT running.\n" + " Run: muxplex service start\n" + ) + sys.exit(1) + # 5. Doctor check print("\n Verifying...") doctor() diff --git a/muxplex/tests/test_cli.py b/muxplex/tests/test_cli.py index 99b3dda..053fe7f 100644 --- a/muxplex/tests/test_cli.py +++ b/muxplex/tests/test_cli.py @@ -3119,3 +3119,174 @@ def test_upgrade_exits_1_after_finally_recovers_stopped_service(monkeypatch, cap assert "error" in out.lower() or "failed" in out.lower(), ( f"upgrade() must print an error message when install fails; got: {out!r}" ) + + +# --------------------------------------------------------------------------- +# v0.6.7 fixes — service-restart verification (Fix 1) +# --------------------------------------------------------------------------- + + +def test_verify_service_started_returns_true_when_active(monkeypatch): + """_verify_service_started returns True when systemctl is-active exits 0 (active).""" + import subprocess + + import muxplex.cli as cli_mod + + monkeypatch.setattr(cli_mod, "_have_systemctl", lambda: True) + monkeypatch.setattr(cli_mod, "_have_launchctl", lambda: False) + monkeypatch.setattr( + subprocess, + "run", + lambda cmd, **kw: type( + "R", (), {"returncode": 0, "stdout": "active\n", "stderr": ""} + )(), + ) + + assert cli_mod._verify_service_started() is True + + +def test_verify_service_started_returns_false_when_inactive(monkeypatch): + """_verify_service_started returns False when systemctl is-active exits 3 (inactive).""" + import subprocess + + import muxplex.cli as cli_mod + + monkeypatch.setattr(cli_mod, "_have_systemctl", lambda: True) + monkeypatch.setattr(cli_mod, "_have_launchctl", lambda: False) + monkeypatch.setattr( + subprocess, + "run", + lambda cmd, **kw: type( + "R", (), {"returncode": 3, "stdout": "inactive\n", "stderr": ""} + )(), + ) + + assert cli_mod._verify_service_started() is False + + +def test_upgrade_exits_1_if_service_fails_to_restart(monkeypatch, capsys): + """upgrade() exits 1 when install succeeds but the service never becomes active.""" + import subprocess + + import muxplex.cli as cli_mod + + calls = [] + + def mock_run(cmd, **kwargs): + calls.append(list(cmd) if isinstance(cmd, list) else cmd) + return type("R", (), {"returncode": 0, "stdout": "enabled\n", "stderr": ""})() + + monkeypatch.setattr(subprocess, "run", mock_run) + monkeypatch.setattr(shutil, "which", lambda name: f"/usr/bin/{name}") + monkeypatch.setattr(cli_mod, "_check_for_update", lambda info: (True, "update available")) + monkeypatch.setattr(cli_mod, "_have_systemctl", lambda: True) + monkeypatch.setattr(cli_mod, "_have_launchctl", lambda: False) + # Service never becomes active (simulates the spark-1 dead-service scenario) + monkeypatch.setattr(cli_mod, "_verify_service_started", lambda timeout_s=10: False) + + with patch("muxplex.service.service_install", lambda: None): + with pytest.raises(SystemExit) as exc_info: + cli_mod.upgrade() + + assert exc_info.value.code == 1, ( + f"upgrade() must exit 1 when service fails to restart; got {exc_info.value.code}" + ) + out = capsys.readouterr().out + assert "error" in out.lower() or "not running" in out.lower(), ( + f"upgrade() must print an error about the failed restart; got: {out!r}" + ) + + +def test_upgrade_calls_daemon_reload_before_start(monkeypatch, capsys): + """upgrade() calls systemctl daemon-reload before start (stale unit-file fix).""" + import subprocess + + import muxplex.cli as cli_mod + + calls: list = [] + + def mock_run(cmd, **kwargs): + calls.append(list(cmd) if isinstance(cmd, list) else cmd) + return type("R", (), {"returncode": 0, "stdout": "enabled\n", "stderr": ""})() + + monkeypatch.setattr(subprocess, "run", mock_run) + monkeypatch.setattr(shutil, "which", lambda name: f"/usr/bin/{name}") + monkeypatch.setattr(cli_mod, "_check_for_update", lambda info: (True, "update available")) + monkeypatch.setattr(cli_mod, "_have_systemctl", lambda: True) + monkeypatch.setattr(cli_mod, "_have_launchctl", lambda: False) + monkeypatch.setattr(cli_mod, "_verify_service_started", lambda timeout_s=10: True) + monkeypatch.setattr(cli_mod, "doctor", lambda: None) + + with patch("muxplex.service.service_install", lambda: None): + cli_mod.upgrade() + + systemctl_calls = [c for c in calls if isinstance(c, list) and "systemctl" in c] + reload_idx = next( + (i for i, c in enumerate(systemctl_calls) if "daemon-reload" in c), None + ) + start_idx = next( + (i for i, c in enumerate(systemctl_calls) if "start" in c and "muxplex" in c), + None, + ) + + assert reload_idx is not None, ( + "systemctl daemon-reload must be called during upgrade" + ) + assert start_idx is not None, ( + "systemctl start muxplex must be called during upgrade" + ) + assert reload_idx < start_idx, ( + "daemon-reload must be called BEFORE start to pick up the regenerated unit file" + ) + + +# --------------------------------------------------------------------------- +# v0.6.7 fixes — doctor launchd port-probe (Fix 2 / doctor enhancement) +# --------------------------------------------------------------------------- + + +def test_doctor_reports_launchd_registered_but_not_serving( + monkeypatch, tmp_path, capsys +): + """doctor() warns when launchd agent is registered but the service port is not responding.""" + import subprocess + import sys + + import muxplex.cli as cli_mod + import muxplex.settings as settings_mod + + # Create plist file so plist.exists() passes + fake_home = tmp_path + plist = fake_home / "Library" / "LaunchAgents" / "com.muxplex.plist" + plist.parent.mkdir(parents=True) + plist.write_text("") + + monkeypatch.setattr(Path, "home", staticmethod(lambda: fake_home)) + + settings_file = tmp_path / "settings.json" + settings_file.write_text("{}") + monkeypatch.setattr(settings_mod, "SETTINGS_PATH", settings_file) + + # Simulate macOS + monkeypatch.setattr(sys, "platform", "darwin") + monkeypatch.setattr(cli_mod, "_have_launchctl", lambda: True) + + # launchctl print succeeds (agent is registered) + monkeypatch.setattr( + subprocess, + "run", + lambda *a, **kw: type( + "R", (), {"returncode": 0, "stdout": "", "stderr": ""} + )(), + ) + + # Port is NOT responding + monkeypatch.setattr(cli_mod, "_probe_service_port", lambda port: False) + + cli_mod.doctor() + + out = capsys.readouterr().out + assert "not serving" in out.lower(), ( + f"doctor() must warn 'not serving' when launchd is registered but port is down;" + f" got: {out!r}" + )