diff --git a/BlocksScreen/lib/panels/mainWindow.py b/BlocksScreen/lib/panels/mainWindow.py index 28b4f74d..5bbbd0b1 100644 --- a/BlocksScreen/lib/panels/mainWindow.py +++ b/BlocksScreen/lib/panels/mainWindow.py @@ -283,6 +283,7 @@ def __init__(self): self.controlPanel.disable_popups.connect(self.popup_toggle) self.updater_worker.status_ready.connect(self.update_page.handle_status_ready) self.updater_worker.busy_changed.connect(self.update_page.handle_busy_changed) + self.updater_worker.replay_busy() self.updater_worker.daemon_unavailable.connect(self.on_updater_unavailable) self.updater_worker.daemon_unavailable.connect( self.update_page.handle_daemon_unavailable diff --git a/BlocksScreen/lib/panels/widgets/MainWindow/updatePage.py b/BlocksScreen/lib/panels/widgets/MainWindow/updatePage.py index 825bd013..f9434cf9 100644 --- a/BlocksScreen/lib/panels/widgets/MainWindow/updatePage.py +++ b/BlocksScreen/lib/panels/widgets/MainWindow/updatePage.py @@ -46,6 +46,13 @@ class UpdatePage(QtWidgets.QWidget): } ) + # Boot provisioning of a missing component reuses steps 1-4 with different meanings. + _PROVISION_STEP_LABELS: typing.ClassVar[MappingProxyType[int, str]] = ( + MappingProxyType( + {1: "cloning", 2: "installing deps", 3: "setting up", 4: "starting"} + ) + ) + _APT_STEP_LABELS: typing.ClassVar[MappingProxyType[int, str]] = MappingProxyType( {1: "updating packages", 2: "upgrading packages"} ) @@ -72,6 +79,8 @@ def __init__(self) -> None: self._update_avail: bool = False self._post_update_status_pending: bool = False self._overlay_shown: bool = False + self._restart_pending: bool = False + self._provisioning: bool = False self._elapsed_time_seconds: int = 0 self._elapsed_timer: QtCore.QTimer = QtCore.QTimer(self) self._elapsed_timer.setSingleShot(False) @@ -335,10 +344,11 @@ def handle_status_ready(self, json_str: str) -> None: self._update_avail = _update_avail if not self._busy: self.show_loading(False) - if self._post_update_status_pending: + if self._post_update_status_pending and not self._restart_pending: _log.debug("status_ready: emitting call_load_panel(False)") self.call_load_panel.emit(False, "", False) self._post_update_status_pending = False + self._overlay_shown = False else: _log.debug("status_ready: skipping loadscreen dismiss (busy=True)") self.build_cards() @@ -350,6 +360,14 @@ def handle_busy_changed(self, busy: bool) -> None: self._busy = busy self.show_loading(busy) if busy: + # Busy with no user press = the daemon is installing a missing component. + self._provisioning = self._provisioning or not self._overlay_shown + if self._provisioning: + self._overlay_shown = True + self.call_load_panel.emit( + True, "Missing component, installing ...", False + ) + self._restart_pending = False self._elapsed_time_seconds = 0 self._elapsed_timer.start() self._busy_timeout_timer.start() @@ -358,17 +376,36 @@ def handle_busy_changed(self, busy: bool) -> None: self._progress_label.show() self._cancel_btn.show() else: + self._provisioning = False self._elapsed_timer.stop() self._busy_timeout_timer.stop() self._elapsed_time_label.hide() self._progress_label.hide() self._cancel_btn.hide() self.update_all_btn.setEnabled(True) - if self._overlay_shown: - self._overlay_shown = False - self.call_load_panel.emit(False, "", False) + if self._restart_pending: + # Keep the overlay up: SIGTERM is imminent, MainWindow would flash. + QtCore.QTimer.singleShot(15000, self._dismiss_after_restart_grace) + elif self._overlay_shown: + # Hold the overlay until fresh status lands, else stale cards flash. + self._post_update_status_pending = True + QtCore.QTimer.singleShot(10000, self._dismiss_stale_overlay) self._request_status_debounced() + def _dismiss_stale_overlay(self) -> None: + """Drop the overlay if the post-update status never arrived.""" + if self._overlay_shown and not self._busy: + self._overlay_shown = False + self._post_update_status_pending = False + self.call_load_panel.emit(False, "", False) + + def _dismiss_after_restart_grace(self) -> None: + """Drop the overlay if the expected UI restart never came.""" + if self._restart_pending and not self._busy: + self._restart_pending = False + self._overlay_shown = False + self.call_load_panel.emit(False, "", False) + @QtCore.pyqtSlot(name="on-update-all-clicked") def on_update_all_clicked(self) -> None: """Guard against updates during a print or with hot heaters; otherwise show confirm dialog.""" @@ -418,6 +455,8 @@ def handle_step_complete(self, name: str, step: int, total: int) -> None: status = self._statuses.get(name) if status and status.kind == "apt": label = self._APT_STEP_LABELS.get(step, "working") + elif self._provisioning: + label = self._PROVISION_STEP_LABELS.get(step, "working") else: label = self._STEP_LABELS.get(step, "working") _log.info("step_complete: %s %d/%d (%s)", name, step, total, label) @@ -425,7 +464,11 @@ def handle_step_complete(self, name: str, step: int, total: int) -> None: if self._busy_timeout_timer.isActive(): self._busy_timeout_timer.start() self._overlay_shown = True - overlay_msg = f"{name}: {label}" + # BlocksScreen's last step restarts this very process. + self._restart_pending = name == "BlocksScreen" and step == total + overlay_msg = ( + f"Installing {name}: {label}" if self._provisioning else f"{name}: {label}" + ) self._progress_label.setText(f"Step {step}/{total}") self.call_load_panel.emit(True, overlay_msg, False) diff --git a/BlocksScreen/lib/updater_worker.py b/BlocksScreen/lib/updater_worker.py index 58ee2e1a..de23f79a 100644 --- a/BlocksScreen/lib/updater_worker.py +++ b/BlocksScreen/lib/updater_worker.py @@ -77,6 +77,8 @@ def __init__(self) -> None: self._last_activity: float = 0.0 # Unique bus name of the live daemon; a change means it restarted. self._daemon_owner: str = "" + # Latest busy state, for replay_busy(); the worker thread runs before MainWindow wires slots. + self._last_busy: bool = False self._owner_task: asyncio.Task | None = None self._escalated: bool = False # Serializes the reconnect and owner-watch entry points into _connect(). @@ -218,12 +220,18 @@ async def _connect(self) -> None: else: self._busy_false_event.set() _log.info("connected to owner %s, busy=%s", self._daemon_owner, busy) + self._last_busy = busy self.busy_changed.emit(busy) if not busy: self.request_reconnect.emit() self.proxy_connected.emit() + def replay_busy(self) -> None: + """Re-emit busy=True once slots are wired; the connect-time emit can fire before they are.""" + if self._last_busy: + self.busy_changed.emit(True) + def _on_listener_done(self, task: asyncio.Task) -> None: """Emit daemon_unavailable and schedule reconnect if a listener exits unexpectedly.""" if task.cancelled(): @@ -591,6 +599,7 @@ async def _listen_busy_changed(self) -> None: async for busy in self._proxy.busy_changed: _log.info("busy_changed received: %s", busy) self._touch_activity() + self._last_busy = busy if busy: self._busy_false_event.clear() task = asyncio.create_task(self._busy_watchdog(), name="busy_watchdog") diff --git a/scripts/install-updater.sh b/scripts/install-updater.sh index 3921f32c..5e8e6b29 100755 --- a/scripts/install-updater.sh +++ b/scripts/install-updater.sh @@ -133,6 +133,8 @@ elif [[ "$(readlink -f "$_BS_SVC_DEST" 2>/dev/null)" != "$(readlink -f "$_BS_SVC sudo systemctl unmask BlocksScreen.service 2>/dev/null || true fi sudo systemctl daemon-reload +# A linked-but-not-enabled UI unit never starts at boot: blank screen and no SSH recovery. +sudo systemctl enable BlocksScreen.service 2>/dev/null || echo_info "WARN: could not enable BlocksScreen.service" echo_ok "BlocksScreen.service is a symlink - hook no longer needs sudo cp" echo_info "Setting up apt cache directory for blocks user ..." diff --git a/tests/lib/test_updater_worker_unit.py b/tests/lib/test_updater_worker_unit.py index 0f9ba42d..3e07e474 100644 --- a/tests/lib/test_updater_worker_unit.py +++ b/tests/lib/test_updater_worker_unit.py @@ -30,6 +30,7 @@ def _make_worker(): w._last_activity = 0.0 w._proxy = MagicMock() w._shutting_down = False + w._last_busy = False w._daemon_owner = "" w._owner_task = None w._escalated = False @@ -510,3 +511,14 @@ def test_shutdown_cancels_owner_watch(self, worker): worker.shutdown() owner_task.cancel.assert_called_once() listener.cancel.assert_called_once() + + +class TestReplayBusy: + def test_replays_true_only(self, worker, qtbot): + received: list[bool] = [] + worker.busy_changed.connect(received.append) + worker.replay_busy() + assert received == [] + worker._last_busy = True + worker.replay_busy() + assert received == [True] diff --git a/tests/updater/conftest.py b/tests/updater/conftest.py index 3afde671..aa5f751f 100644 --- a/tests/updater/conftest.py +++ b/tests/updater/conftest.py @@ -49,6 +49,8 @@ def svc(): ) mock_svc.recover = AsyncMock() mock_svc.has_fetch_failures = MagicMock(return_value=False) + mock_svc.needs_provision = MagicMock(return_value=False) + mock_svc.provision_missing = AsyncMock(return_value=False) mock_svc._components = [ ComponentConfig(name="moonraker", kind="git"), ComponentConfig(name="klipper", kind="git"), @@ -63,6 +65,7 @@ def svc(): s = UpdaterDbusService.__new__(UpdaterDbusService) s._svc = mock_svc s._busy = False + s._boot_busy = False s._background_tasks = set() s._status_check_in_progress = False s._status_pending = False diff --git a/tests/updater/test_dbus_service_unit.py b/tests/updater/test_dbus_service_unit.py index acc4381f..d5c68021 100644 --- a/tests/updater/test_dbus_service_unit.py +++ b/tests/updater/test_dbus_service_unit.py @@ -349,6 +349,77 @@ async def test_periodic_check_never_lengthens_a_short_poll_interval(self, svc): assert sleeps == [3.0, 42.0] +class TestBootProvisionBusy: + def _build(self, missing): + from updater import dbus_service + + mock_svc = MagicMock() + mock_svc.needs_provision.return_value = missing + with ( + patch.object(dbus_service, "UpdateService", return_value=mock_svc), + patch.object(dbus_service.UpdaterDbusService, "_spawn", MagicMock()), + ): + return dbus_service.UpdaterDbusService() + + @pytest.mark.parametrize("missing", [True, False]) + def test_busy_at_construction_iff_component_missing(self, missing): + """Busy must be set before export so the UI's get_busy on connect sees the provision.""" + assert self._build(missing)._busy is missing + + @pytest.mark.asyncio + async def test_boot_busy_skips_initial_sleep_and_releases(self, svc): + """Missing component: provision runs at once (no 3 s sleep), then busy drops.""" + from updater import dbus_service + + svc._boot_busy = svc._busy = True + sleeps: list[float] = [] + + async def fake_sleep(delay): + sleeps.append(delay) + raise asyncio.CancelledError + + with ( + patch.object(dbus_service.asyncio, "sleep", fake_sleep), + pytest.raises(asyncio.CancelledError), + ): + await svc._periodic_status_check() + + assert sleeps == [svc._svc.poll_interval] + assert svc._boot_busy is False + assert svc._busy is False + + +class TestProvisionRetry: + @pytest.mark.asyncio + async def test_retries_while_lock_defers_then_stops(self, svc): + """Deferred provisioning (lock held by boot reconcile) is retried, not left for the next poll.""" + from updater import dbus_service + + svc._svc.needs_provision = MagicMock(side_effect=[True, True, False]) + sleeps: list[float] = [] + + async def fake_sleep(delay): + sleeps.append(delay) + + with patch.object(dbus_service.asyncio, "sleep", fake_sleep): + await svc._provision_with_retry() + + assert svc._svc.provision_missing.await_count == 3 + assert sleeps == [dbus_service._PROVISION_RETRY_S] * 2 + + @pytest.mark.asyncio + async def test_gives_up_after_bounded_retries(self, svc): + """A component that never provisions must not loop forever.""" + from updater import dbus_service + + svc._svc.needs_provision = MagicMock(return_value=True) + + with patch.object(dbus_service.asyncio, "sleep", AsyncMock()): + await svc._provision_with_retry() + + assert svc._svc.provision_missing.await_count == dbus_service._PROVISION_RETRIES + + class TestMethodReturnValues: @pytest.mark.asyncio async def test_update_all_rejected_when_busy_returns_false(self, svc): @@ -422,6 +493,21 @@ async def test_update_all_includes_errored_git_repo(self, svc): assert "RF50-Klipper" in called_with assert "klipper" not in called_with # clean repo not updated + @pytest.mark.asyncio + @pytest.mark.parametrize( + ("restart_pending", "apt_spawned"), [(True, False), (False, True)] + ) + async def test_background_apt_skipped_when_daemon_restart_pending( + self, svc, restart_pending, apt_spawned + ): + """A pending daemon restart would SIGKILL apt mid-run, so the pass is skipped.""" + svc._svc.check_status = AsyncMock(return_value={}) + svc._svc.background_apt_upgrade = AsyncMock() + svc._svc.daemon_restart_pending = restart_pending + await svc._run_update_all() + await asyncio.sleep(0) # let a spawned task run + assert svc._svc.background_apt_upgrade.called is apt_spawned + class TestLockHeldSurfacesError: def _held_lock(self): diff --git a/tests/updater/test_executor_unit.py b/tests/updater/test_executor_unit.py index f0f53d2a..be1ffbcc 100644 --- a/tests/updater/test_executor_unit.py +++ b/tests/updater/test_executor_unit.py @@ -1382,7 +1382,9 @@ async def test_returns_true_on_2xx(self): @pytest.mark.asyncio async def test_times_out_when_never_ready(self): with patch("updater.executor._http_probe", return_value=False): - assert await wait_for_http_ready("http://127.0.0.1:7912/x", timeout=0) is False + assert ( + await wait_for_http_ready("http://127.0.0.1:7912/x", timeout=0) is False + ) @pytest.mark.asyncio async def test_polls_until_ready(self): diff --git a/tests/updater/test_service_unit.py b/tests/updater/test_service_unit.py index b51ff640..367932c7 100644 --- a/tests/updater/test_service_unit.py +++ b/tests/updater/test_service_unit.py @@ -1753,10 +1753,12 @@ async def test_provision_waits_for_service_active(self, tmp_path): return_value=(True, ""), ), patch("updater.service.run_hook", return_value=(True, "")), + patch("updater.service.is_service_active", return_value=False), patch("updater.service.restart_service", return_value=(True, "")), patch( "updater.service.wait_for_service_active", return_value=False ) as mock_wait, + patch("updater.service.stop_service", return_value=(True, "")) as mock_stop, patch("updater.service.shutil.rmtree") as mock_rmtree, ): svc = UpdateService(callback=cb) @@ -1764,6 +1766,7 @@ async def test_provision_waits_for_service_active(self, tmp_path): ok = await svc.update_component("newcomp") assert ok is False mock_wait.assert_called_once() + mock_stop.assert_called_once_with("newcomp.service") mock_rmtree.assert_called_once() assert cb.on_error.call_args[0][1] == "restart" @@ -1783,11 +1786,13 @@ async def test_provision_fails_when_health_check_fails(self, tmp_path): return_value=(True, ""), ), patch("updater.service.run_hook", return_value=(True, "")), + patch("updater.service.is_service_active", return_value=False), patch("updater.service.restart_service", return_value=(True, "")), patch("updater.service.wait_for_service_active", return_value=True), patch( "updater.service.wait_for_http_ready", return_value=False ) as mock_health, + patch("updater.service.stop_service", return_value=(True, "")) as mock_stop, patch("updater.service.shutil.rmtree") as mock_rmtree, ): svc = UpdateService(callback=cb) @@ -1795,6 +1800,7 @@ async def test_provision_fails_when_health_check_fails(self, tmp_path): ok = await svc.update_component("newcomp") assert ok is False mock_health.assert_called_once() + mock_stop.assert_called_once_with("newcomp.service") mock_rmtree.assert_called_once() assert cb.on_error.call_args[0][1] == "restart" @@ -1814,6 +1820,7 @@ async def test_provision_succeeds_when_health_ready(self, tmp_path): return_value=(True, ""), ), patch("updater.service.run_hook", return_value=(True, "")), + patch("updater.service.is_service_active", return_value=False), patch("updater.service.restart_service", return_value=(True, "")), patch("updater.service.wait_for_service_active", return_value=True), patch( @@ -1826,10 +1833,39 @@ async def test_provision_succeeds_when_health_ready(self, tmp_path): svc._components = [comp] ok = await svc.update_component("newcomp") assert ok is True - mock_health.assert_called_once_with("http://127.0.0.1:7912/health") + mock_health.assert_called_once_with( + "http://127.0.0.1:7912/health", service="newcomp.service" + ) mock_rmtree.assert_not_called() cb.on_component_done.assert_called_with("newcomp", True) + @pytest.mark.asyncio + async def test_provision_skips_restart_when_hook_started_service(self, tmp_path): + comp = self._comp( + tmp_path, + service="newcomp.service", + health_url="http://127.0.0.1:7912/health", + ) + cb = MagicMock() + with ( + patch("updater.service.git_clone", return_value=(True, "")), + patch("updater.service.git_get_hash", return_value="newhash"), + patch( + "updater.service.UpdateService._install_dependencies", + return_value=(True, ""), + ), + patch("updater.service.run_hook", return_value=(True, "")), + patch("updater.service.is_service_active", return_value=True), + patch("updater.service.restart_service") as mock_restart, + patch("updater.service.wait_for_http_ready", return_value=True), + patch("updater.service.enable_service", return_value=(True, "")), + ): + svc = UpdateService(callback=cb) + svc._components = [comp] + ok = await svc.update_component("newcomp") + assert ok is True + mock_restart.assert_not_called() + @pytest.mark.asyncio async def test_check_status_reports_needs_install(self, tmp_path): comp = self._comp(tmp_path) @@ -2361,6 +2397,7 @@ async def test_install_touches_deploy_flag_not_restart(self, tmp_path: Path): mock_restart.assert_not_called() mock_verify.assert_not_called() assert not sentinel.exists() # consumed + assert svc.daemon_restart_pending is True @pytest.mark.asyncio async def test_code_restarts_only_when_importable(self, tmp_path: Path): @@ -2377,6 +2414,7 @@ async def test_code_restarts_only_when_importable(self, tmp_path: Path): svc = self._svc_with_ui() await svc._apply_deferred_restart() mock_restart.assert_called_once_with("BlocksScreen-updater.service") + assert svc.daemon_restart_pending is True @pytest.mark.asyncio async def test_code_skips_restart_when_not_importable(self, tmp_path: Path): @@ -2394,6 +2432,7 @@ async def test_code_skips_restart_when_not_importable(self, tmp_path: Path): svc = self._svc_with_ui() await svc._apply_deferred_restart() mock_restart.assert_not_called() + assert svc.daemon_restart_pending is False def test_read_clear_sentinel_install_outranks_code(self, tmp_path: Path): sentinel = tmp_path / "updater-restart-needed" diff --git a/tests/widgets/test_update_page_unit.py b/tests/widgets/test_update_page_unit.py index 26980da0..b5ab1207 100644 --- a/tests/widgets/test_update_page_unit.py +++ b/tests/widgets/test_update_page_unit.py @@ -11,8 +11,12 @@ def page(qapp): """UpdatePage instance with all heavy UI deps mocked.""" patches = [ - patch("BlocksScreen.lib.panels.widgets.MainWindow.updatePage.LoadingOverlayWidget"), - patch("BlocksScreen.lib.panels.widgets.MainWindow.updatePage.BlocksCustomButton"), + patch( + "BlocksScreen.lib.panels.widgets.MainWindow.updatePage.LoadingOverlayWidget" + ), + patch( + "BlocksScreen.lib.panels.widgets.MainWindow.updatePage.BlocksCustomButton" + ), patch("BlocksScreen.lib.panels.widgets.MainWindow.updatePage.IconButton"), ] for p in patches: @@ -307,12 +311,22 @@ def test_false_does_not_emit_call_load_panel_when_no_overlay(self, page, qtbot): with qtbot.assertNotEmitted(page.call_load_panel, wait=200): page.handle_busy_changed(False) - def test_false_emits_call_load_panel_when_overlay_shown(self, page, qtbot): + def test_false_holds_overlay_until_status_ready(self, page, qtbot): page.show_loading = MagicMock() page._overlay_shown = True - with qtbot.waitSignal(page.call_load_panel, timeout=200) as blocker: + with qtbot.assertNotEmitted(page.call_load_panel, wait=200): page.handle_busy_changed(False) - assert blocker.args == [False, "",False] + assert page._overlay_shown is True + with qtbot.waitSignal(page.call_load_panel, timeout=200) as blocker: + page.handle_status_ready(_make_payload()) + assert blocker.args == [False, "", False] + assert page._overlay_shown is False + + def test_stale_overlay_fallback_dismisses(self, page, qtbot): + page._overlay_shown = True + page._busy = False + with qtbot.waitSignal(page.call_load_panel, timeout=200): + page._dismiss_stale_overlay() assert page._overlay_shown is False def test_true_starts_elapsed_timer(self, page): @@ -413,13 +427,13 @@ class TestHandleStepComplete: def test_emits_call_load_panel_with_step_message(self, page, qtbot): with qtbot.waitSignal(page.call_load_panel, timeout=200) as blocker: page.handle_step_complete("klipper", 1, 4) - assert blocker.args == [True, "klipper: fetching",False] + assert blocker.args == [True, "klipper: fetching", False] page._progress_label.setText.assert_called_with("Step 1/4") def test_unknown_steps_falls_back_to_working(self, page, qtbot): with qtbot.waitSignal(page.call_load_panel, timeout=200) as blocker: page.handle_step_complete("moonraker", 99, 4) - assert blocker.args == [True, "moonraker: working",False] + assert blocker.args == [True, "moonraker: working", False] page._progress_label.setText.assert_called_with("Step 99/4") @@ -498,7 +512,9 @@ def test_bad_payload_keeps_statuses_and_toasts(self, page): class TestConfirmPopupCleanup: def test_second_confirm_deletes_previous_popup(self, page): - with patch("BlocksScreen.lib.panels.widgets.MainWindow.updatePage.BasePopup") as popup_cls: + with patch( + "BlocksScreen.lib.panels.widgets.MainWindow.updatePage.BasePopup" + ) as popup_cls: first = MagicMock() second = MagicMock() popup_cls.side_effect = [first, second] @@ -506,3 +522,32 @@ def test_second_confirm_deletes_previous_popup(self, page): page._show_update_confirm() first.deleteLater.assert_called_once() second.deleteLater.assert_not_called() + + +class TestBootProvisioning: + def test_busy_without_user_press_shows_installing_message(self, page, qtbot): + page.show_loading = MagicMock() + with qtbot.waitSignal(page.call_load_panel, timeout=200) as blocker: + page.handle_busy_changed(True) + assert blocker.args == [True, "Missing component, installing ...", False] + + def test_provision_steps_name_the_component(self, page, qtbot): + page.show_loading = MagicMock() + page.handle_busy_changed(True) + with qtbot.waitSignal(page.call_load_panel, timeout=200) as blocker: + page.handle_step_complete("Spoolman", 1, 4) + assert blocker.args == [True, "Installing Spoolman: cloning", False] + + def test_user_update_keeps_update_labels(self, page, qtbot): + page.show_loading = MagicMock() + page._overlay_shown = True + page.handle_busy_changed(True) + with qtbot.waitSignal(page.call_load_panel, timeout=200) as blocker: + page.handle_step_complete("klipper", 1, 4) + assert blocker.args == [True, "klipper: fetching", False] + + def test_replayed_busy_keeps_provisioning(self, page): + page.show_loading = MagicMock() + page.handle_busy_changed(True) + page.handle_busy_changed(True) + assert page._provisioning is True diff --git a/updater/dbus_service.py b/updater/dbus_service.py index 3e1b6b14..94576be7 100644 --- a/updater/dbus_service.py +++ b/updater/dbus_service.py @@ -20,6 +20,9 @@ _STATUS_PATH = Path("/run/blockscreen/updater_status.json") # Poll again this soon while a git fetch is failing: a boot-time DNS miss must not hide updates for a full poll interval. _FETCH_RETRY_INTERVAL_S = 300.0 +# Boot reconcile holds the process lock briefly; provisioning is deferred, not lost. +_PROVISION_RETRIES = 10 +_PROVISION_RETRY_S = 3.0 class DbusProgressCallback: @@ -102,7 +105,9 @@ def __init__(self) -> None: """Wire the service and busy state, then spawn the boot, poll, and self-heal tasks.""" super().__init__() self._svc = UpdateService(callback=DbusProgressCallback(self)) - self._busy: bool = False + # Busy before export so the UI's get_busy on connect sees a boot provision, not a MainWindow flash. + self._boot_busy: bool = self._svc.needs_provision() + self._busy: bool = self._boot_busy self._background_tasks: set[asyncio.Task] = set() self._status_check_in_progress: bool = False self._status_pending: bool = False @@ -129,6 +134,21 @@ def _task_done(self, task: asyncio.Task) -> None: if exc is not None: _log.error("task %r failed", task.get_name(), exc_info=exc) + async def _provision_with_retry(self) -> None: + """Retry while boot reconcile still holds the process lock and defers provisioning.""" + for attempt in range(_PROVISION_RETRIES): + await self._svc.provision_missing(self._set_busy) + if not self._svc.needs_provision(): + return + if attempt + 1 < _PROVISION_RETRIES: + await asyncio.sleep(_PROVISION_RETRY_S) + + def _release_boot_busy(self) -> None: + """Drop the busy state pre-set at boot; no await between this and provision's own busy(False).""" + if self._boot_busy: + self._boot_busy = False + self._set_busy(False) + def _set_busy(self, busy: bool) -> None: """Emit busy_changed only on state transitions to avoid redundant signals.""" if busy != self._busy: @@ -191,14 +211,17 @@ async def _emit_status(self, force: bool = False) -> None: async def _periodic_status_check(self) -> None: """Emit status shortly after startup, then at the poll interval - or sooner while fetches fail.""" - await asyncio.sleep(3.0) + if not self._boot_busy: + await asyncio.sleep(3.0) while True: try: + # Provision first (a no-op stat when nothing is missing) so status reflects it. + await self._provision_with_retry() + self._release_boot_busy() await self._emit_status() - if await self._svc.provision_missing(): - await self._emit_status() # reflect freshly-installed components except Exception as exc: # noqa: BLE001 _log.error("periodic_check failed: %s", exc) + self._release_boot_busy() interval = self._svc.poll_interval if self._svc.has_fetch_failures(): interval = min(_FETCH_RETRY_INTERVAL_S, interval) @@ -275,7 +298,10 @@ async def _run_update_all(self) -> None: self._update_all_locked, "update_all", "updater" ) # Silent apt pass only if we held the lock; else the CLI run owns apt. - if ran: + if ran and self._svc.daemon_restart_pending: + # A SIGKILL from the restart could land inside dpkg; the next poll re-offers the packages. + _log.info("background apt upgrade skipped: daemon restart pending") + elif ran: self._spawn( self._svc.background_apt_upgrade(), name="background_apt_upgrade" ) diff --git a/updater/executor.py b/updater/executor.py index 2c171b16..3e9e7c35 100644 --- a/updater/executor.py +++ b/updater/executor.py @@ -995,6 +995,13 @@ async def enable_service(name: str | None) -> tuple[bool, str]: return await _run([SUDO, SYSTEMCTL, "enable", name], timeout=15.0) +async def is_service_active(name: str) -> bool: + """One-shot systemctl is-active probe.""" + if not _SERVICE_RE.match(name): + return False + return (await _run([SYSTEMCTL, "is-active", name], timeout=10.0))[0] + + async def wait_for_service_active(name: str, timeout: float = 90.0) -> bool: """Poll systemctl is-active until active or timeout.""" if not _SERVICE_RE.match(name): @@ -1034,13 +1041,22 @@ def _http_probe(url: str) -> bool: conn.close() -async def wait_for_http_ready(url: str, timeout: float = 120.0) -> bool: - """Poll a component's loopback health URL until it returns 2xx or timeout.""" +async def wait_for_http_ready( + url: str, timeout: float = 120.0, *, service: str | None = None +) -> bool: + """Poll a health URL until 2xx or timeout; fail fast if `service` leaves active.""" deadline = asyncio.get_running_loop().time() + timeout while True: if await asyncio.to_thread(_http_probe, url): logger.info("health check ok: %s", url) return True + # A crash-looping unit is 'activating', never 'active': don't wait out the timeout. + if ( + service + and not (await _run([SYSTEMCTL, "is-active", service], timeout=10.0))[0] + ): + logger.warning("service %r left active during health check", service) + return False if asyncio.get_running_loop().time() >= deadline: logger.warning("health check timed out after %.0fs: %s", timeout, url) return False @@ -1070,6 +1086,15 @@ async def verify_updater_importable(component_path: Path | None) -> bool: return ok +async def stop_service(name: str | None) -> tuple[bool, str]: + """Stop a systemd service.""" + if name is None: + return (False, "service name is None") + if not _SERVICE_RE.match(name): + return (False, f"service name {name!r} is invalid") + return await _run([SUDO, SYSTEMCTL, "stop", name], timeout=30.0) + + async def restart_service(name: str | None) -> tuple[bool, str]: """Restart a systemd service, recovering from a start-limit hit.""" if name is None: diff --git a/updater/service.py b/updater/service.py index 1eb09a88..e5fd9aaf 100644 --- a/updater/service.py +++ b/updater/service.py @@ -47,9 +47,11 @@ git_tree_has_path, git_untracked_paths, is_git_repo, + is_service_active, restart_service, restart_service_noblock, run_hook, + stop_service, verify_updater_importable, wait_for_http_ready, wait_for_service_active, @@ -258,6 +260,8 @@ def __init__(self, callback: ProgressCallback | None = None) -> None: self._log = logging.getLogger("updater") # Self-heal: trailing-window sample ring for crash-loop detection. self._nrestarts_samples: dict[str, list[tuple[float, int]]] = {} + # Set once this daemon is about to be stopped, so no apt child gets SIGKILLed with it. + self.daemon_restart_pending = False def has_component(self, name: str) -> bool: """Return True if a component with the given name is registered.""" @@ -476,15 +480,25 @@ async def _filter_dead_branch_batch(self, batch: list[ComponentConfig]) -> bool: ) return ok - async def provision_missing(self) -> bool: - """Clone absent install_if_missing components at boot (no manual update).""" - missing = [ + def _missing_provisions(self) -> list[ComponentConfig]: + """install_if_missing components whose directory is absent.""" + return [ c for c in self._components if c.install_if_missing and c.url and (c.path is None or not c.path.exists()) ] + + def needs_provision(self) -> bool: + """True if provision_missing() would clone something (cheap filesystem check).""" + return bool(self._missing_provisions()) + + async def provision_missing( + self, on_busy: Callable[[bool], None] | None = None + ) -> bool: + """Clone absent install_if_missing components at boot; on_busy brackets the work.""" + missing = self._missing_provisions() if not missing: return False provisioned = False @@ -492,10 +506,16 @@ async def provision_missing(self) -> bool: if not acquired: self._log.info("provision_missing: update in progress, deferring") return False - for c in missing: - if c.path is None or not c.path.exists(): # recheck under lock - await self._provision_component(c) - provisioned = True + if on_busy: + on_busy(True) # UI shows step_complete only while busy + try: + for c in missing: + if c.path is None or not c.path.exists(): # recheck under lock + await self._provision_component(c) + provisioned = True + finally: + if on_busy: + on_busy(False) return provisioned async def _preflight_fetch( @@ -995,6 +1015,7 @@ async def _apply_deferred_restart(self) -> None: "(install-updater runs out-of-band)" ) await asyncio.to_thread(self._touch_deploy_flag) + self.daemon_restart_pending = True return comp = next( (c for c in self._components if c.service in _FIRE_AND_FORGET_SERVICES), @@ -1012,6 +1033,7 @@ async def _apply_deferred_restart(self) -> None: UPDATER_SERVICE, ) await restart_service_noblock(UPDATER_SERVICE) + self.daemon_restart_pending = True except Exception: # noqa: BLE001 self._log.error("deferred restart handling failed", exc_info=True) @@ -1695,6 +1717,9 @@ async def _remove_clone(self, component: ComponentConfig) -> None: async def _fail_provision(self, component: ComponentConfig, reason: str) -> bool: """Remove the partial clone, log, and report failure.""" + if component.service and reason in ("hook", "restart"): + # Else systemd crash-loops the unit on the deleted dir until StartLimit. + await stop_service(component.service) await self._remove_clone(component) self._history("install_failed", component.name, reason=reason) self._log.warning( @@ -1708,7 +1733,12 @@ async def _provision_restart_service( """Restart+health-check+enable the provisioned service; fail reason or None.""" if not component.service: return None - if not await self._restart_one(component.service, component.health_url): + if await is_service_active(component.service): + # The hook already started it (enable --now): a restart would start it twice. + ok = await self._await_health(component.service, component.health_url) + else: + ok = await self._restart_one(component.service, component.health_url) + if not ok: return "restart" # Enable only after a clean start (no boot-looping failed unit). en_ok, en_err = await enable_service(component.service) @@ -1972,6 +2002,14 @@ async def _stage_component(self, component: ComponentConfig) -> tuple[bool, str] return guard return await self._stage_apply_ref(component, tip) + async def _await_health(self, service: str, health_url: str | None) -> bool: + """Verify an already-running service answers its health URL.""" + if health_url and not await wait_for_http_ready(health_url, service=service): + self._log.error("%s active but health check failed", service) + return False + self._log.info("%s already active, restart skipped", service) + return True + async def _restart_one(self, service: str, health_url: str | None = None) -> bool: """Restart a service and verify it came active (kill-fallback aware).""" self._log.info("restarting %s and waiting for active", service) @@ -1982,7 +2020,7 @@ async def _restart_one(self, service: str, health_url: str | None = None) -> boo if not await wait_for_service_active(service, timeout=90.0): self._log.error("%s did not become active after restart", service) return False - if health_url and not await wait_for_http_ready(health_url): + if health_url and not await wait_for_http_ready(health_url, service=service): self._log.error("%s active but health check failed", service) return False self._log.info("%s active after restart", service)