From 594f3d890c296658b0f48eb158c7f5b40e3ed5b2 Mon Sep 17 00:00:00 2001 From: Stefan Agner Date: Fri, 13 Feb 2026 15:15:29 +0100 Subject: [PATCH] Move periodic progress logging to DockerInterface for all image pulls Move the periodic progress logging from HomeAssistantCore.install() down to DockerInterface.install() so that all container image pulls (Core, add-ons, plugins) benefit from visibility during long pulls. Every 15 seconds, a log message reports the current pull progress percentage or indicates the pull is still in progress if no progress data is available. Co-Authored-By: Claude Opus 4.6 --- supervisor/docker/interface.py | 26 ++++++++++++++ supervisor/homeassistant/core.py | 59 +++++++++----------------------- tests/docker/test_interface.py | 40 ++++++++++++++++++++++ tests/homeassistant/test_core.py | 53 ---------------------------- 4 files changed, 83 insertions(+), 95 deletions(-) diff --git a/supervisor/docker/interface.py b/supervisor/docker/interface.py index ce5e4d664..1069df4da 100644 --- a/supervisor/docker/interface.py +++ b/supervisor/docker/interface.py @@ -3,6 +3,7 @@ from __future__ import annotations from abc import ABC, abstractmethod +import asyncio from collections import defaultdict from collections.abc import Awaitable from contextlib import suppress @@ -291,6 +292,29 @@ class DockerInterface(JobGroup, ABC): ) _LOGGER.info("Downloading docker image %s with tag %s.", image, version) + stop_progress_log = asyncio.Event() + + async def _periodic_progress_log() -> None: + """Log pull progress periodically for user visibility.""" + while not stop_progress_log.is_set(): + try: + await asyncio.wait_for(stop_progress_log.wait(), timeout=15) + except TimeoutError: + if current_job.progress: + _LOGGER.info( + "Pulling %s:%s, %d%%", + image, + version, + int(current_job.progress), + ) + else: + _LOGGER.info( + "Pulling %s:%s still in progress", + image, + version, + ) + + progress_task = self.sys_create_task(_periodic_progress_log()) try: # Get credentials for private registries to pass to aiodocker credentials = self._get_credentials(image) or None @@ -326,6 +350,8 @@ class DockerInterface(JobGroup, ABC): ) from err finally: self.sys_bus.remove_listener(listener) + stop_progress_log.set() + await progress_task self._meta = docker_image diff --git a/supervisor/homeassistant/core.py b/supervisor/homeassistant/core.py index bb3008c6c..754e17564 100644 --- a/supervisor/homeassistant/core.py +++ b/supervisor/homeassistant/core.py @@ -184,51 +184,26 @@ class HomeAssistantCore(JobGroup): async def install(self) -> None: """Install Home Assistant Core.""" _LOGGER.info("Home Assistant setup") - stop_progress_log = asyncio.Event() + while True: + # read homeassistant tag and install it + if not self.sys_homeassistant.latest_version: + await self.sys_updater.reload() - async def _periodic_progress_log() -> None: - """Log installation progress periodically for user visibility.""" - while not stop_progress_log.is_set(): + if to_version := self.sys_homeassistant.latest_version: try: - await asyncio.wait_for(stop_progress_log.wait(), timeout=15) - except TimeoutError: - if (job := self.instance.active_job) and job.progress: - _LOGGER.info( - "Downloading Home Assistant Core image, %d%%", - int(job.progress), - ) - else: - _LOGGER.info("Home Assistant Core installation in progress") + await self.instance.update( + to_version, + image=self.sys_updater.image_homeassistant, + ) + self.sys_homeassistant.version = self.instance.version or to_version + break + except (DockerError, JobException): + pass + except Exception as err: # pylint: disable=broad-except + await async_capture_exception(err) - progress_task = self.sys_create_task(_periodic_progress_log()) - try: - while True: - # read homeassistant tag and install it - if not self.sys_homeassistant.latest_version: - await self.sys_updater.reload() - - if to_version := self.sys_homeassistant.latest_version: - try: - await self.instance.update( - to_version, - image=self.sys_updater.image_homeassistant, - ) - self.sys_homeassistant.version = ( - self.instance.version or to_version - ) - break - except (DockerError, JobException): - pass - except Exception as err: # pylint: disable=broad-except - await async_capture_exception(err) - - _LOGGER.warning( - "Error on Home Assistant installation. Retrying in 30sec" - ) - await asyncio.sleep(30) - finally: - stop_progress_log.set() - await progress_task + _LOGGER.warning("Error on Home Assistant installation. Retrying in 30sec") + await asyncio.sleep(30) _LOGGER.info("Home Assistant docker now installed") self.sys_homeassistant.set_image(self.sys_updater.image_homeassistant) diff --git a/tests/docker/test_interface.py b/tests/docker/test_interface.py index a0353ba91..54850aefa 100644 --- a/tests/docker/test_interface.py +++ b/tests/docker/test_interface.py @@ -870,3 +870,43 @@ async def test_install_progress_containerd_snapshot( job_event(100), job_event(100, True), ] + + +@pytest.mark.parametrize( + ("progress", "expected_log"), + [ + (0, "Pulling test:1.2.3 still in progress"), + (45.0, "Pulling test:1.2.3, 45%"), + ], +) +async def test_install_logs_progress_periodically( + coresys: CoreSys, + test_docker_interface: DockerInterface, + caplog: pytest.LogCaptureFixture, + progress: float, + expected_log: str, +): + """Test install logs progress periodically during image pull.""" + original_wait_for = asyncio.wait_for + fired = False + + async def mock_wait_for(coro, *, timeout=None): + """Immediately timeout once for the progress log wait.""" + nonlocal fired + if timeout == 15 and not fired: + fired = True + coro.close() + # Set desired progress on the job created by @Job decorator + if progress: + for job in coresys.jobs.jobs: + if job.name == "docker_interface_install": + job.progress = progress + break + await asyncio.sleep(0) + raise TimeoutError + return await original_wait_for(coro, timeout=timeout) + + with patch("supervisor.docker.interface.asyncio.wait_for", new=mock_wait_for): + await test_docker_interface.install(AwesomeVersion("1.2.3"), "test") + + assert expected_log in caplog.text diff --git a/tests/homeassistant/test_core.py b/tests/homeassistant/test_core.py index 090cefb6d..5f0386dfd 100644 --- a/tests/homeassistant/test_core.py +++ b/tests/homeassistant/test_core.py @@ -1,6 +1,5 @@ """Test Home Assistant core.""" -import asyncio from datetime import datetime, timedelta from http import HTTPStatus from unittest.mock import ANY, MagicMock, Mock, PropertyMock, call, patch @@ -207,58 +206,6 @@ async def test_install_other_error( assert "Unhandled exception:" not in caplog.text -@pytest.mark.parametrize( - ("active_job", "expected_log"), - [ - (None, "Home Assistant Core installation in progress"), - (MagicMock(progress=45.0), "Downloading Home Assistant Core image, 45%"), - ], -) -async def test_install_logs_progress_periodically( - coresys: CoreSys, - caplog: pytest.LogCaptureFixture, - active_job: MagicMock | None, - expected_log: str, -): - """Test install logs progress periodically during image pull.""" - coresys.security.force = True - coresys.docker.images.pull.return_value = AsyncIterator([{}]) - original_wait_for = asyncio.wait_for - - async def mock_wait_for(coro, *, timeout=None): - """Immediately timeout for the progress log wait, pass through others.""" - if timeout == 15: - coro.close() - await asyncio.sleep(0) - raise TimeoutError - return await original_wait_for(coro, timeout=timeout) - - with ( - patch.object(HomeAssistantCore, "start"), - patch.object(DockerHomeAssistant, "cleanup"), - patch.object( - Updater, - "image_homeassistant", - new=PropertyMock(return_value="homeassistant"), - ), - patch.object( - Updater, "version_homeassistant", new=PropertyMock(return_value="2022.7.3") - ), - patch.object( - DockerInterface, "arch", new=PropertyMock(return_value=CpuArch.AMD64) - ), - patch("supervisor.homeassistant.core.asyncio.wait_for", new=mock_wait_for), - patch.object( - DockerHomeAssistant, - "active_job", - new=PropertyMock(return_value=active_job), - ), - ): - await coresys.homeassistant.core.install() - - assert expected_log in caplog.text - - @pytest.mark.parametrize( ("container_exc", "image_exc", "delete_calls"), [