From b2d9b91a6602ba8336d11d0bf7e823ebefa0de12 Mon Sep 17 00:00:00 2001 From: Chuck <33324927+ChuckBuilds@users.noreply.github.com> Date: Thu, 17 Sep 2026 09:05:07 -0400 Subject: [PATCH] fix(update): keep the rollback's pip retries inside the unit time limit The health check reinstalled the previous requirements by trying the next bash path after any failure, including a 600 s pip timeout. Two files, two paths: up to 40 minutes of pip alone, while systemd stops ledmatrix-update-verify.service at TimeoutStartSec=30min -- killing the rollback half-way and leaving the update 'verifying' until the web UI calls it lost. - Like permission_utils.install_requirements_file, only a sudo refusal moves on to the next bash; a pip that ran and failed or timed out is not repeated. The refusal wording is one list (permission_utils.SUDO_REFUSAL_PHRASES), mirrored in the stdlib-only verifier and pinned equal by a test. - All reinstalls in one rollback share a 600 s budget. - WORST_CASE_SECONDS adds up every timeout on the longest path (27.5 min); a test holds it under the unit's TimeoutStartSec and that under the web UI's VERIFY_LOST_SECONDS. Co-Authored-By: Claude Opus 5 --- scripts/utils/auto_update_verify.py | 56 ++++++++++++++++----- src/common/permission_utils.py | 13 +++-- test/test_auto_update_verify.py | 76 +++++++++++++++++++++++++++++ 3 files changed, 130 insertions(+), 15 deletions(-) diff --git a/scripts/utils/auto_update_verify.py b/scripts/utils/auto_update_verify.py index 787933fd..d089cbec 100644 --- a/scripts/utils/auto_update_verify.py +++ b/scripts/utils/auto_update_verify.py @@ -42,10 +42,30 @@ HEALTH_TIMEOUT_SECONDS = 180 #: loop look healthy between attempts, so a single "is-active" proves nothing. STABLE_SECONDS = 45 POLL_SECONDS = 5 +WEB_CHECK_TIMEOUT_SECONDS = 5 +SYSTEMCTL_QUERY_TIMEOUT_SECONDS = 10 +RESTART_TIMEOUT_SECONDS = 90 +GIT_TIMEOUT_SECONDS = 60 +GIT_RESET_TIMEOUT_SECONDS = 120 PIP_TIMEOUT_SECONDS = 600 +#: All of a rollback's dependency reinstalls together. A pip that times out +#: or fails is not retried: systemd stops this unit at TimeoutStartSec, and a +#: rollback killed half-way leaves the update reported as still verifying. +PIP_BUDGET_SECONDS = 600 #: sudoers matches the exact command line, so bash is named by path, the same -#: candidates src/common/permission_utils.install_requirements_file tries. +#: candidates src/common/permission_utils.install_requirements_file tries... BASH_CANDIDATES = ('/usr/bin/bash', '/bin/bash') +#: ...and, like it, moves to the next one only when sudo refused the command +#: line (permission_utils.SUDO_REFUSAL_PHRASES), never after pip itself ran. +SUDO_REFUSAL_PHRASES = ('a password is required', 'is not allowed to run', 'no tty present') + +#: The longest one health check can take: restart and wait, roll back +#: (diff, reset, reinstalls), restart and wait again. A wait's last poll can +#: start just before its deadline and run every query to its timeout. +_WAIT_WORST_SECONDS = (HEALTH_TIMEOUT_SECONDS + STABLE_SECONDS + WEB_CHECK_TIMEOUT_SECONDS + + 2 * SYSTEMCTL_QUERY_TIMEOUT_SECONDS + POLL_SECONDS) +WORST_CASE_SECONDS = (2 * (2 * RESTART_TIMEOUT_SECONDS + _WAIT_WORST_SECONDS) + + GIT_TIMEOUT_SECONDS + GIT_RESET_TIMEOUT_SECONDS + PIP_BUDGET_SECONDS) #: What a command that could not run at all reports: its callers only read #: these three fields, the same ones a completed subprocess has. @@ -83,7 +103,7 @@ def write_pending(path, data): def _web_responds(url=WEB_HEALTH_URL): try: - with urllib.request.urlopen(url, timeout=5) as resp: # nosec B310 - fixed loopback URL + with urllib.request.urlopen(url, timeout=WEB_CHECK_TIMEOUT_SECONDS) as resp: # nosec B310 - fixed loopback URL return resp.status == 200 except (urllib.error.URLError, OSError, ValueError): return False @@ -104,7 +124,7 @@ class Verifier: self.web_responds = web_responds self.log = log or (lambda msg: print(f'[auto-update-verify] {msg}', flush=True)) - def _run(self, args, timeout=60): + def _run(self, args, timeout=GIT_TIMEOUT_SECONDS): try: return self.run(args, cwd=str(self.project_root), capture_output=True, text=True, timeout=timeout) @@ -114,15 +134,17 @@ class Verifier: # -- services --------------------------------------------------------- def service_active(self, unit): - return self._run(['systemctl', 'is-active', unit], timeout=10).stdout.strip() == 'active' + return self._run(['systemctl', 'is-active', unit], + timeout=SYSTEMCTL_QUERY_TIMEOUT_SECONDS).stdout.strip() == 'active' def restart_count(self, unit): out = self._run(['systemctl', 'show', '-p', 'NRestarts', '--value', unit], - timeout=10).stdout.strip() + timeout=SYSTEMCTL_QUERY_TIMEOUT_SECONDS).stdout.strip() return int(out) if out.isdigit() else None def restart(self, unit): - result = self._run(['sudo', '-n', 'systemctl', 'restart', f'{unit}.service'], timeout=90) + result = self._run(['sudo', '-n', 'systemctl', 'restart', f'{unit}.service'], + timeout=RESTART_TIMEOUT_SECONDS) if result.returncode != 0: self.log(f'restarting {unit} failed: {(result.stderr or "").strip()}') return result.returncode == 0 @@ -173,16 +195,27 @@ class Verifier: changed = set(result.stdout.split()) if result.returncode == 0 else set(REQUIREMENT_FILES) return [rel for rel in REQUIREMENT_FILES if rel in changed] - def install_requirements(self, rel): + def install_requirements(self, rel, deadline=None): + """Install one requirements file through the root wrapper, by ``deadline``.""" wrapper = self.project_root / 'scripts' / 'fix_perms' / 'safe_pip_install.sh' req = self.project_root / rel if not req.exists(): return True for bash in BASH_CANDIDATES: - result = self._run(['sudo', '-n', bash, str(wrapper), str(req)], - timeout=PIP_TIMEOUT_SECONDS) + timeout = PIP_TIMEOUT_SECONDS + if deadline is not None: + timeout = min(timeout, deadline - self.clock()) + if timeout <= 0: + self.log(f'no time left to reinstall {rel}') + return False + result = self._run(['sudo', '-n', bash, str(wrapper), str(req)], timeout=timeout) if result.returncode == 0: return True + # Only a refused command line is worth the next candidate. A pip + # that ran and failed, or timed out, would just do it again. + if not any(phrase in (result.stderr or '') for phrase in SUDO_REFUSAL_PHRASES): + self.log(f'reinstalling {rel} failed: {(result.stderr or "").strip()[-300:]}') + return False return False def rollback(self, pending): @@ -196,11 +229,12 @@ class Verifier: # plugin folders the only thing this discards is the update. Edits # under plugins/ and plugin-repos/, which that check leaves to the # pull's --autostash, are reset along with it. - result = self._run(['git', 'reset', '--hard', old], timeout=120) + result = self._run(['git', 'reset', '--hard', old], timeout=GIT_RESET_TIMEOUT_SECONDS) if result.returncode != 0: return False, (f'"git reset --hard {old}" failed: ' f'{(result.stderr or result.stdout or "").strip()}') - failed = [rel for rel in requirements if not self.install_requirements(rel)] + deadline = self.clock() + PIP_BUDGET_SECONDS + failed = [rel for rel in requirements if not self.install_requirements(rel, deadline)] if failed: return True, ('reinstalling the previous dependencies from ' + ', '.join(failed) + ' failed; run Install Base Requirements from the Tools tab') diff --git a/src/common/permission_utils.py b/src/common/permission_utils.py index 29be2f04..f59b31cc 100644 --- a/src/common/permission_utils.py +++ b/src/common/permission_utils.py @@ -373,6 +373,14 @@ def sudo_remove_directory(path: Path, allowed_bases: Optional[list] = None) -> b return False +#: What sudo prints when it refuses a command line outright (not in sudoers for +#: that exact argv, or it wants a password). Only then is another bash path +#: worth trying: after pip itself ran, a retry just repeats the failure. The +#: automatic update's health check keeps its own copy of this list +#: (scripts/utils/auto_update_verify.py runs without importing src/). +SUDO_REFUSAL_PHRASES = ("a password is required", "is not allowed to run", "no tty present") + + def install_requirements_file(req_file: Path, timeout: int = 300) -> subprocess.CompletedProcess: """ Install a requirements.txt file for a plugin (or the project itself). @@ -434,10 +442,7 @@ def install_requirements_file(req_file: Path, timeout: int = 300) -> subprocess. # Distinguish "sudo rejected this exact command line" (worth # trying the next bash candidate) from "sudo ran it but pip # itself failed" (a real error — stop and surface it). - denied = any( - phrase in result.stderr - for phrase in ("a password is required", "is not allowed to run", "no tty present") - ) + denied = any(phrase in result.stderr for phrase in SUDO_REFUSAL_PHRASES) if not denied: # Deliberately don't interpolate req_file or the pip output here: # this log line is scanner-visible, and a static analyzer can't diff --git a/test/test_auto_update_verify.py b/test/test_auto_update_verify.py index 8a6c06c2..c346091e 100644 --- a/test/test_auto_update_verify.py +++ b/test/test_auto_update_verify.py @@ -69,6 +69,8 @@ class FakeHost: self.running_head = None # not restarted yet: still the old, healthy code self.restarts = [] # (unit, commit it was restarted onto) self.pip_installs = [] + self.pip_timeouts = [] + self.pip = None # optional (args, host) -> result, or raises, instead of pip_ok self.now = 0.0 self.nrestarts = 0 @@ -90,6 +92,9 @@ class FakeHost: return done(args, f'{self.nrestarts}\n') if args[0] == 'sudo' and any(a.endswith('safe_pip_install.sh') for a in args): self.pip_installs.append(args[-1]) + self.pip_timeouts.append(kwargs.get('timeout')) + if self.pip: + return self.pip(args, self) return done(args, rc=0 if self.pip_ok else 1) if args[:4] == ['sudo', '-n', 'systemctl', 'restart']: if self.restart_failures: @@ -171,6 +176,77 @@ def test_a_failed_dependency_reinstall_is_reported(tmp_path): assert 'Install Base Requirements' in result['detail'] +def _rollback_with_pip(tmp_path, pip, web_requirements_too=False): + """Roll back an update that changed the requirements, with pip faked by ``pip``.""" + repo, old, new = updated_repo(tmp_path, new_requirements=True) + if web_requirements_too: + (repo / 'web_interface').mkdir() + (repo / 'web_interface' / 'requirements.txt').write_text('flask\n') + git(repo, 'add', '.') + git(repo, 'commit', '-qm', 'web reqs') + (repo / 'web_interface' / 'requirements.txt').write_text('flask\nnew\n') + (repo / 'requirements.txt').write_text('requests\nnewer\n') + git(repo, 'commit', '-qam', 'bump both') + old, new = git(repo, 'rev-parse', 'HEAD~1'), git(repo, 'rev-parse', 'HEAD') + host = FakeHost(repo, new) + host.pip = pip + ok, detail = host.verifier().rollback({'old_head': old, 'new_head': new}) + return ok, detail, host + + +def test_a_failed_pip_is_not_run_again_with_the_other_bash(tmp_path): + """Retrying after pip itself ran only repeats it, and every repeat can + take PIP_TIMEOUT_SECONDS of the unit's time limit.""" + ok, detail, host = _rollback_with_pip( + tmp_path, lambda args, h: subprocess.CompletedProcess(args, 1, '', 'ERROR: No matching distribution')) + assert ok and 'requirements.txt' in detail + assert len(host.pip_installs) == 1 + + +def test_a_pip_timeout_is_not_retried(tmp_path): + def slow(args, h): + h.now += h.pip_timeouts[-1] + raise subprocess.TimeoutExpired(args, h.pip_timeouts[-1]) + ok, detail, host = _rollback_with_pip(tmp_path, slow) + assert ok and 'Install Base Requirements' in detail + assert len(host.pip_installs) == 1 + + +def test_a_sudo_refusal_tries_the_next_bash(tmp_path): + def refused_once(args, h): + if len(h.pip_installs) == 1: + return subprocess.CompletedProcess(args, 1, '', 'sudo: a password is required') + return done(args) + ok, detail, host = _rollback_with_pip(tmp_path, refused_once) + assert ok and detail == '' + assert len(host.pip_installs) == 2 + + +def test_reinstalls_share_one_time_budget(tmp_path): + def hangs(args, h): + h.now += h.pip_timeouts[-1] + raise subprocess.TimeoutExpired(args, h.pip_timeouts[-1]) + ok, detail, host = _rollback_with_pip(tmp_path, hangs, web_requirements_too=True) + assert ok and 'requirements.txt' in detail and 'web_interface/requirements.txt' in detail + assert sum(host.pip_timeouts) <= av.PIP_BUDGET_SECONDS + assert len(host.pip_installs) == 1, "the first file used the whole budget" + + +def test_the_worst_case_fits_the_unit_time_limit(): + """systemd kills the check at TimeoutStartSec, mid-rollback, and the update + then sits in "verifying" until the web interface calls it lost.""" + from web_interface import auto_update as au + service = (ROOT / 'systemd' / 'ledmatrix-update-verify.service').read_text(encoding='utf-8') + minutes = int(re.search(r'^TimeoutStartSec=(\d+)min$', service, re.M).group(1)) + assert av.WORST_CASE_SECONDS < minutes * 60 + assert minutes * 60 < au.VERIFY_LOST_SECONDS, "the web UI must not call a running check lost" + + +def test_sudo_refusal_wording_matches_permission_utils(): + from src.common import permission_utils + assert set(av.SUDO_REFUSAL_PHRASES) == set(permission_utils.SUDO_REFUSAL_PHRASES) + + def test_still_broken_after_rolling_back_is_rollback_failed(tmp_path): code, result, host, head, old, new = check(tmp_path, 'always') assert code == 1 and result['status'] == 'rollback_failed'